Ускоряем hugo на 20% простым изменением в пакете reflect

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

Я был удивлён, когда в top10 списке CPU-профиля hugo при сборке digitalgov.gov на первой позиции находился метод reflect.Type.MethodByName().

      flat  flat%   sum%        cum   cum%      8.84s  6.28%  6.28%     57.85s 41.10%  reflect.(*rtype).MethodByName      7.93s  5.63% 11.92%      8.50s  6.04%  reflect.name.readVarint      7.56s  5.37% 17.29%    111.79s 79.43%  reflect.Value.call      7.53s  5.35% 22.64%     23.33s 16.58%  runtime.mallocgc      7.29s  5.18% 27.82%     16.10s 11.44%  reflect.name.name

В этой статье я расскажу вам о том, как так вышло и что с этим можно было бы сделать.

Почему MethodByName такой медленный

Давайте откроем исходники MethodByName:

func (t *rtype) MethodByName(name string) (m Method, ok bool) {     // <лишний код вырезан>      // TODO(mdempsky): Binary search.     for i, p := range ut.exportedMethods() {         if t.nameOff(p.name).name() == name {             return t.Method(i), true         }     }     return Method{}, false }

MethodByName использует линейный поиск. Если экспортируемых методов у типа много, то работать это может очень долго, особенно если искомый метод будет находиться где-то в конце слайса.

Как можно ускорить MethodByName

Вариант первый: не использовать MethodByName. Или кешировать результат. Но будем считать, что мы не можем этого сделать.

func (t *rtype) MethodByName(name string) (m Method, ok bool) {     // <лишний код вырезан>      if len(methods) > 8 {         i := sort.Search(len(methods), func(i int) bool {             return t.nameOff(methods[i].name).name() >= name         })         if i < len(methods) && t.nameOff(methods[i].name).name() == name {             return t.Method(i), true         }     } else {         for i, p := range methods {             if t.nameOff(p.name).name() == name {                 return t.Method(i), true             }         }     }     return Method{}, false }

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

Если мы напишем бенчмарки, то получим примерно такие цифры:

name                           old time/op  new time/op  delta MethodByName/4_first-8          426ns ± 2%   423ns ± 1%     ~    MethodByName/4_last-8           482ns ± 1%   476ns ± 1%   -1.33% MethodByName/4_nonexisting-8   57.8ns ± 0%  57.3ns ± 1%   -0.78% MethodByName/16_first-8         427ns ± 1%   538ns ± 0%  +25.97% MethodByName/16_last-8          643ns ± 1%   519ns ± 1%  -19.24% MethodByName/16_nonexisting-8   194ns ± 0%   105ns ± 0%  -46.03% MethodByName/32_first-8         429ns ± 1%   552ns ± 1%  +28.78% MethodByName/32_last-8          831ns ± 0%   540ns ± 2%  -34.97% MethodByName/32_nonexisting-8   396ns ± 1%   125ns ± 1%  -68.56% MethodByName/64_first-8         431ns ± 1%   580ns ± 2%  +34.64% MethodByName/64_last-8         1.36µs ± 1%  0.56µs ± 1%  -58.95% MethodByName/64_nonexisting-8   759ns ± 0%   146ns ± 1%  -80.82% [Geo mean]                      430ns        303ns       -29.58%

Как и ожидалось, новый метод работает хуже для случаев, когда искомый метод находится в начале слайса. Если учесть, что это вырожденный случаи и в среднем метод будет находиться где-то в середине, то выигрыш довольно очевиден.

Проверяем влияние на hugo

Изначально, указанный выше сайт собирался за 20.4 секунды.

Соберём hugo с обновлённым пакетом reflect и запустим сборку сайта ещё раз.

Невероятно, сборка сайта теперь занимает 16.5 секунд!

А что же там с профилем?

(pprof) top 20 Showing nodes accounting for 50.85s, 44.61% of 114s total Dropped 1174 nodes (cum <= 0.57s) Showing top 20 nodes out of 194       flat  flat%   sum%        cum   cum%      8.64s  7.58%  7.58%     25.01s 21.94%  runtime.mallocgc      7.69s  6.75% 14.32%     87.02s 76.33%  reflect.Value.call      4.17s  3.66% 17.98%      5.39s  4.73%  runtime.heapBitsSetType      2.88s  2.53% 20.51%         4s  3.51%  runtime.findObject      2.83s  2.48% 22.99%      2.83s  2.48%  runtime.nextFreeFast (inline)      2.79s  2.45% 25.44%      9.46s  8.30%  runtime.scanobject      2.74s  2.40% 27.84%      2.74s  2.40%  runtime.duffcopy      1.82s  1.60% 29.44%      1.88s  1.65%  runtime.pageIndexOf      1.76s  1.54% 30.98%      1.76s  1.54%  runtime.memclrNoHeapPointers      1.69s  1.48% 32.46%      3.24s  2.84%  runtime.mapaccess2      1.66s  1.46% 33.92%      1.83s  1.61%  syscall.Syscall      1.49s  1.31% 35.23%      1.61s  1.41%  reflect.name.readVarint      1.43s  1.25% 36.48%      3.07s  2.69%  reflect.name.name      1.42s  1.25% 37.73%     10.54s  9.25%  reflect.FuncOf      1.37s  1.20% 38.93%      1.75s  1.54%  github.com/gohugoio/hugo/...      1.34s  1.18% 40.11%      4.99s  4.38%  sync.(*Map).Load      1.33s  1.17% 41.27%      1.33s  1.17%  reflect.(*rtype).Kind      1.29s  1.13% 42.40%      1.29s  1.13%  cmpbody      1.28s  1.12% 43.53%      1.28s  1.12%  runtime.resolveNameOff      1.23s  1.08% 44.61%      1.30s  1.14%  runtime.heapBitsForAddr

MethodByName, который был на 1-ой позиции, теперь не входит даже в top20.

Но нам стоит копнуть глубже, чтобы делать какие-либо выводы. Давайте посчитаем сколько там было вызовов MethodByName и каково распределение размеров слайсов exportedMethods и позиций, на которых метод был найден.

Общее количество вызовов за сборку сайта: 17042238.

15920637 times | 120 methods 493669 times | 29 methods 227736 times | 16 methods 180098 times | 8 methods 143846 times | 39 methods 31371 times | 6 methods 14636 times | 1 methods 10933 times | 31 methods 10094 times | 9 methods 9026 times | 4 methods 102 times | 113 methods 85 times | 7 methods 4 times | 114 methods 1 times | 0 methods

Большая часть вызовов была над типом, у которого 120 экспортируемых методов.

12998952 times | 98 index pos 1203864 times | 70 index pos 515978 times | 102 index pos 354191 times | 110 index pos 262965 times | 6 index pos 200819 times | 11 index pos 178457 times | 19 index pos 170806 times | 97 index pos 147510 times | 74 index pos 136927 times | 3 index pos 123071 times | 20 index pos 106250 times | 9 index pos 87190 times | 7 index pos 62767 times | 31 index pos 62192 times | 5 index pos 50170 times | 51 index pos 49120 times | 69 index pos 45325 times | 72 index pos 42236 times | 115 index pos 38646 times | 0 index pos 37106 times | 28 index pos 22744 times | 108 index pos 21521 times | 14 index pos 18134 times | 92 index pos 17341 times | 4 index pos 11535 times | 103 index pos 10791 times | 63 index pos 10303 times | 2 index pos 9170 times | 10 index pos 7278 times | 68 index pos 5936 times | 15 index pos 5466 times | 65 index pos 5385 times | 16 index pos 5172 times | 47 index pos 4478 times | 43 index pos 3032 times | 40 index pos 2340 times | 17 index pos 2265 times | 25 index pos 1516 times | 44 index pos 1068 times | 88 index pos 843 times | 1 index pos 709 times | 71 index pos 358 times | 109 index pos 100 times | 67 index pos 50 times | 64 index pos 40 times | 42 index pos 33 times | 34 index pos 17 times | 86 index pos 15 times | 83 index pos 15 times | 41 index pos 15 times | 33 index pos 12 times | 118 index pos 5 times | 8 index pos 5 times | 27 index pos 4 times | 66 index pos

Распределение индексов искомых методов тоже подсказывает, что линейный поиск в данном случае — не лучший выбор. Большая часть методов находилась на позиции 98.

Подводные камни

В коде выше я использовал sort.Search, но он не доступен для пакета reflect.

Дело в том, что пакет sort импортирует reflect, поэтому мы получаем ошибку циклических импортов.

Чтобы этого избежать, можно продублировать реализацию sort.Search в пакете reflect или создать новый internal пакет для Go, где будет некоторое подмножество пакета sort, не зависящее от reflect.

Этот фактор немного затрудняет внедрение предлагаемого патча, ведь самый красивый вариант реализации нам недоступен.

Как воспроизвести результаты, собрать профили

$ git clone https://github.com/GSA/digitalgov.gov.git $ cd digitalgov.gov $ hugo --profile-cpu cpu.out

Далее используем go tool pprof для анализа профиля cpu.out.

Я использовал hugo с коммита c8b5ab75b743914f89b51046eee8e3daa2eb1eec. Но думаю примерно такие же результаты можно получить и с других версий.

В digitalgov.gov надо будет поправить пару файлов, убрав использования getenv или добавив их в исключения.

    modified:   themes/digital.gov/layouts/partials/core/head.html     modified:   themes/digital.gov/layouts/partials/core/set-env.html

Версия Go особо значения не имеет, потому что линейный поиск в MethodByName был всегда.

Выводы

Я выслал CL с изменениями в Go, но не знаю, примут его или нет (spoiler: скорее всего нет).

В любом случае, было забавно увидеть как такая безобидная на первый взгляд операция замедляла сборку статического сайта на какое-то значительное время.

Немного другого я ожидал от hugo с заголовком «The world’s fastest framework for building websites.»

Если вдруг вы хотите поставить +1 к высланному патчу, сделать это можно, оставив реакцию к golang/issue50617.