Профилировщик памяти LuaJIT
В Tarantool, начиная с версии 2.7.1, есть встроенный модуль misc.memprof
, реализующий профилировщик памяти LuaJIT (далее в разделе — профилировщик). Профилировщик предоставляет отчет об аллокации памяти, который помогает проанализовать Lua-код и выявить области наибольшей нагрузки на сборщик мусора на Lua.
Использование профилировщика
Работа с профилировщиком состоит из двух этапов:
- События аллокации, реаллокации и деаллокации в Lua собираются в бинарный профиль (далее по тексту — бинарный профиль памяти или просто бинарный профиль).
- Выполняется парсинг собранного бинарного профиля. В результате формируется отчет о профилировании в удобном для чтения формате.
Сбор бинарного профиля
Чтобы сформировать бинарный профиль для определенного участка кода на Lua, вставьте этот участок кода между функциями misc.memprof.start()
и misc.memprof.stop()
, а затем выполните его в Tarantool.
Для наглядности ниже приведен фрагмент кода на Lua под названием test.lua
.
1-- Отключение аллокации на трассах
2jit.off()
3local str, err = misc.memprof.start("memprof_new.bin")
4-- Lua не создает стековый фрейм для вызова string.rep,
5-- поэтому все события аллокации
6-- приписываются не функции append(), а родительской области
7local function append(str, rep)
8 return string.rep(str, rep)
9end
10
11local t = {}
12for i = 1, 1e4 do
13 -- table.insert — встроенная функция,
14 -- так что профилировщик включает все соответствующие ей
15 -- события аллокации в отчет по основной части кода
16 table.insert(t,
17 append('q', i)
18 )
19end
20local stp, err = misc.memprof.stop()
В примере test.lua код для запуска профилировщика находится на строке 3:
local str, err = misc.memprof.start(ИМЯ_ФАЙЛА)
ИМЯ_ФАЙЛА
— имя бинарного файла, куда записываются профилируемые события.
Если операция завершается ошибкой, функция misc.memprof.start()
возвращает результат, состоящий из трех частей: nil
; строка с сообщением об ошибке; код ошибки в зависимости от системы. Ошибка может возникнуть, например, когда не открывается файл для записи или профилировщик уже запущен. Если операция выполняется успешно, misc.memprof.start()
возвращает true
.
В примере test.lua код для остановки профилировщика находится на строке 18:
local stp, err = misc.memprof.stop()
Если операция завершается ошибкой, функция misc.memprof.stop()
возвращает результат, состоящий из трех частей: nil
; строка с сообщением об ошибке; код ошибки в зависимости от системы. Ошибка может возникнуть, например, когда закрыт файловый дескриптор или во время составления отчета происходит сбой. Если операция выполняется успешно, misc.memprof.stop()
возвращает true
.
Теперь нужно сгенерировать файл с профилем памяти в бинарном формате. В примере test.lua имя файла — memprof_new.bin
. Выполните код в Tarantool:
$ tarantool test.lua
Tarantool собирает события аллокации в файл memprof_new.bin
, помещает его в рабочую директорию и завершает сеанс.
Пример test.lua также иллюстрирует логику, по которой в некоторых случаях происходит аллокация памяти. Важно понимать эту логику, чтобы читать и анализировать отчеты о профилировании.
- Строка 2: Рекомендуется отключать JIT-компиляцию, вызывая
jit.off()
перед запуском профилировщика. За дополнительными сведениями обратитесь к примечанию о jitoff.
- Строки 6–8: Оптимизация хвостового вызова не создает новый фрейм стека вызовов, поэтому все события аллокации в байт-коде
CALLT/CALLMT
относятся на счет кода, вызывающего эту функцию. Обратите внимание на комментарии перед этими строками.
- Строки 14–16: Как правило, разработчиков несильно интересует информация об аллокации во встроенных функциях LuaJIT. Поэтому если встроенная функция вызывается из функции на Lua, профилировщик собирает все события аллокации для функции на Lua. В противном случае событие относится к функции на C. Обратите внимание на комментарии перед этими строками.
Парсинг бинарного профиля и формирование отчета о профилировании
Получив профиль памяти в двоичном формате, нужно выполнить парсинг, чтобы отчет было удобно читать. Парсинг можно выполнить в Tarantool, воспользовавшись следующей командой (обратите внимание на дефис -
перед именем файла):
$ tarantool -e 'require("memprof")(arg)' - memprof_new.bin
Здесь memprof_new.bin
— бинарный профиль, ранее сгенерированный командой tarantool test.lua
. (Внимание: в версии Tarantool 2.8.1 поведение команды tarantool -e
немного изменилось.)
Tarantool генерирует отчет о профилировании и выводит его в консоль перед закрытием сеанса:
ALLOCATIONS
@test.lua:14: 10000 events +50240518 bytes -0 bytes
@test.lua:9: 1 events +32 bytes -0 bytes
@test.lua:8: 1 events +20 bytes -0 bytes
@test.lua:13: 1 events +24 bytes -0 bytes
REALLOCATIONS
@test.lua:13: 13 events +262216 bytes -131160 bytes
Overrides:
@test.lua:13
@test.lua:14: 11 events +49536 bytes -24768 bytes
Overrides:
@test.lua:14
INTERNAL
INTERNAL: 3 events +8448 bytes -16896 bytes
Overrides:
@test.lua:14
DEALLOCATIONS
INTERNAL: 1723 events +0 bytes -483515 bytes
@test.lua:14: 1 events +0 bytes -32768 bytes
HEAP SUMMARY:
@test.lua:14 holds 50248326 bytes: 10010 allocs, 10 frees
@test.lua:13 holds 131080 bytes: 14 allocs, 13 frees
INTERNAL holds 8448 bytes: 3 allocs, 3 frees
@test.lua:9 holds 32 bytes: 1 allocs, 0 frees
@test.lua:8 holds 20 bytes: 1 allocs, 0 frees
Примечание
В macOS отчет по той же части кода выглядит по-другому, поскольку Tarantool и LuaJIT собраны с поддержкой режима GC64 для macOS.
Рассмотрим структуру отчета. Он состоит из четырех разделов:
- ALLOCATIONS (аллокация)
- REALLOCATIONS (реаллокация)
- DEALLOCATIONS (деаллокация)
- HEAP SUMMARY (cводка изменений в динамической памяти, раздел описан ниже)
Записи в каждом разделе отсортированы в порядке от наиболее до наименее частых событий.
Запись о событии регистрируется в следующем формате:
@<имя_файла>:<номер_строки>: <количество_событий> events +<выделенные_байты> bytes -<освобожденные_байты> bytes
- <имя_файла> — имя файла, содержащего код на Lua.
- <номер_строки> — номер строки, в которой обнаружено событие.
- <количество_событий> — количество событий для этой строки кода.
- +<выделенная_память_в_байтах> bytes — объем выделенной памяти для всех событий в этой строке.
- +<освобожденная_память_в_байтах> bytes — объем освобожденной памяти для всех событий в этой строке.
Метка Overrides
на событии показывает, какое событие аллокации оно замещает.
См. код примера test.lua выше и пояснения в комментариях к нему.
Метка INTERNAL
показывает, что событие произошло во внутренних структурах LuaJIT.
Примечание
Важное примечание о метке INTERNAL
и рекомендации отключать компиляцию JIT (jit.off()
). В текущей версии профилировщика не поддерживается подробное (verbose) описание событий аллокации при трассировке. Если память выделяется во время трассировки, профилировщик не может соотнести события аллокации с соответствующей частью кода. В этом случае профилировщик помечает такие события как INTERNAL
.
Когда компиляция JIT включена, выполняется несколько процессов трассировки. В результате пометку INTERNAL
в отчете о профилировании получают самые разные события: некоторые из них действительно возникают во внутренних структурах LuaJIT, а другие вызваны аллокацией при трассировке.
Вы можете получить более конкретный отчет, в который не входят события аллокации, вызванные JIT-компилятором. Для этого до запуска профилировщика вызовите jit.off(). Чтобы полностью исключить из отчета аллокацию на трассах, удалите предыдущие трассы, вызвав после jit.off()
функцию jit.flush()
.
Отключать компиляцию JIT перед запуском профилировщика рекомендуется, но это не обязательно. Например, в производственной среде без компиляции JIT полное представление об аллокациях памяти получить невозможно. В подобных случаях большая часть событий INTERNAL
, вероятнее всего, происходит при трассировках.
Иногда отчет о профилировании помогает исследовать код на Lua. Однако этот метод подходит не для любого кода, так что рекомендаций на этот счет нет. Посмотрите пример анализа отчета о профилировании, чтобы узнать, как можно использовать отчет для исследования кода.
Больше информации о том, как использовать профилировщик, вы найдете ниже в разделе Вопросы и ответы.
Вопросы и ответы
В этом разделе даются ответы на часто задаваемые вопросы о работе профилировщика.
Вопрос (В): Проверяет ли профилировщик аллокацию в C и коде на C?
Ответ (A): Профилировщик включает в отчет только события выделения памяти Lua-аллокатором. Отчет содержит все события аллокации в Lua, например создание таблиц и строк. Однако профилировщик не отслеживает выделение памяти с помощью malloc()
или действия аллокаторов, не связанных с Lua. Чтобы фиксировать такие события, для отладки можно использовать valgrind
.
В: Почему у меня в отчете о профилировании столько событий аллокации INTERNAL
? Что это значит?
О: Пометка INTERNAL
означает, что событие аллокации/реаллокации/деаллокации связано с внутренними структурами LuaJIT или трассами. Сейчас профилировщик не включает в отчет подробное описание событий аллокации для объектов, создаваемых на трассах. Попробуйте перед запуском профилировщика добавить jit.off().
В: Почему на некоторых событиях аллокации/деаллокации нет метки Overrides
?
О: Вероятно, события связаны с объектами, созданными до запуска профилировщика. Если перед запуском профилировщика добавить вызов collectgarbage()
, то будут учитываться и события, связанные с «мертвыми» объектами: под такие объекты ранее была выделена память, но на момент запуска профилировщика они уже недоступны.
В: Почему некоторые объекты не учитываются при профилировании? Это связано с утечкой памяти?
О: LuaJIT использует инкрементальный сборщик мусора. Когда профилировщик завершает работу, цикл сборки мусора может все еще выполняться. Чтобы обеспечить профилирование «мертвых» объектов, добавьте collectgarbage()
перед командой остановки профилировщика.
В: Можно ли профилировать не только часть кода, а все приложение? Можно ли запустить профилировщик во время работы приложения?
О: Да. Вот пример кода, который можно вставить в консоль Tarantool, когда приложение уже запущено:
1local fiber = require "fiber"
2local log = require "log"
3
4fiber.create(function()
5 fiber.name("memprof")
6
7 collectgarbage() -- Сбор мертвых объектов
8 log.warn("start of profile")
9
10 local st, err = misc.memprof.start(ИМЯ_ФАЙЛА)
11 if not st then
12 log.error("failed to start profiler: %s", err)
13 end
14
15 fiber.sleep(ВРЕМЯ)
16
17 collectgarbage()
18 st, err = misc.memprof.stop()
19
20 if not st then
21 log.error("profiler on stop error: %s", err)
22 end
23
24 log.warn("end of profile")
25end)
Пояснения:
ИМЯ_ФАЙЛА
— имя бинарного файла, куда записываются профилируемые события.
ВРЕМЯ
— продолжительность профилирования в секундах.
Кроме того, вызывать misc.memprof.start()
и misc.memprof.stop()
можно напрямую из консоли.
Пример анализа отчета о профилировании
Ниже приведен код на Lua — файл format_concat.lua
. Этот код будет исследован с применением отчетов о профилировании памяти.
1-- Отключение аллокации на новых трассах
2jit.off()
3
4local function concat(a)
5 local nstr = a.."a"
6 return nstr
7end
8
9local function format(a)
10 local nstr = string.format("%sa", a)
11 return nstr
12end
13
14collectgarbage()
15
16local binfile = "/tmp/memprof_"..(arg[0]):match("([^/]*).lua")..".bin"
17
18local st, err = misc.memprof.start(binfile)
19assert(st, err)
20
21-- Нагрузка
22for i = 1, 10000 do
23 local f = format(i)
24 local c = concat(i)
25end
26collectgarbage()
27
28local st, err = misc.memprof.stop()
29assert(st, err)
30
31os.exit()
Запустив этот код в Tarantool и выполнив последующий парсинг бинарного профиля в /tmp/memprof_format_concat.bin, вы получите такой отчет о профилировании:
ALLOCATIONS
@format_concat.lua:10: 19996 events +624284 bytes -0 bytes
INTERNAL: 1 events +65536 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 19996 events +0 bytes -558778 bytes
Overrides:
@format_concat.lua:10
@format_concat.lua:10: 2 events +0 bytes -98304 bytes
Overrides:
@format_concat.lua:10
HEAP SUMMARY:
INTERNAL holds 65536 bytes: 1 allocs, 0 frees
Отчет может вызвать такие вопросы:
- Почему нет событий по функции
concat()
?
- Почему количество событий — это не целое число?
- Почему в отчете не 10 тысяч событий, а около 20 тысяч?
Во-первых, LuaJIT не создает новую строку, если уже есть строка с такой же нагрузкой (подробнее на сайте lua-users.org/wiki). Это называется интернированием строк. Иными словами, если строка создана с помощью функции format()
, нет необходимости создавать такую же строку с помощью функции concat()
— LuaJIT будет использовать предыдущую.
По этой же причине количество событий аллокации — это не целое число, как можно было бы ожидать при использовании оператора цикла for i = 1, 10000...
. Некоторые строки Tarantool создает для внутренних нужд и встроенных модулей, поэтому часть строк уже существует.
Но откуда столько событий аллокации? Их почти в 2 раза больше, чем можно было бы ожидать. Это происходит потому, что встроенная функция string.format()
каждый раз создает дополнительную строку для идентификатора %s
. То есть в каждой итерации регистрируются два события аллокации: для tostring(i)
и для string.format("%sa", string_i_value)
. Добавив строку local _ = tostring(i)
между строками 22 и 23, вы увидите разницу в поведении.
Чтобы профилировать только функцию concat()
, закомментируйте строку 23 (local f = format(i)
) и запустите профилировщик. Теперь результат будет такой:
ALLOCATIONS
@format_concat.lua:5: 10000 events +284411 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 10000 events +0 bytes -218905 bytes
Overrides:
@format_concat.lua:5
@format_concat.lua:5: 1 events +0 bytes -32768 bytes
HEAP SUMMARY:
@format_concat.lua:5 holds 65536 bytes: 10000 allocs, 9999 frees
В: Что изменится, если включить компиляцию JIT?
О: Закомментируйте вторую строку (jit.off()
) в коде и запустите профилировщик. Теперь в отчете только 56 событий. Остальные события связаны с JIT (см. также соответствующую задачу на GitHub):
ALLOCATIONS
@format_concat.lua:5: 56 events +1112 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
INTERNAL: 2 events +382 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 58 events +0 bytes -1164 bytes
Overrides:
@format_concat.lua:5
INTERNAL
HEAP SUMMARY:
@format_concat.lua:0 holds 640 bytes: 4 allocs, 0 frees
INTERNAL holds 360 bytes: 2 allocs, 1 frees
Так произошло потому, что трассировка была скомпилирована после 56 итераций (это значение параметра компилятора hotloop
по умолчанию). Затем JIT-компилятор удалил из трассировки неиспользуемую переменную c
, а вместе с ней и неиспользуемый код функции concat()
.
Теперь включите компиляцию JIT и запустите профилирование только для функции format()
. Для этого закомментируйте строки 2 и 24 (jit.off()
и local c = concat(i)
), раскомментируйте строку 23 (local f = format(i)
) и вызовите профилировщик. Результат будет такой:
ALLOCATIONS
@format_concat.lua:10: 19996 events +624284 bytes -0 bytes
INTERNAL: 4 events +66928 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 19997 events +0 bytes -559034 bytes
Overrides:
@format_concat.lua:0
@format_concat.lua:10
@format_concat.lua:10: 2 events +0 bytes -98304 bytes
Overrides:
@format_concat.lua:10
HEAP SUMMARY:
INTERNAL holds 66928 bytes: 4 allocs, 0 frees
@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees
В: Откуда так много событий аллокации по сравнению с concat()
?
О: Ответ прост: LuaJIT еще не скомпилировал функцию string.format()
с идентификатором %s
. Поэтому трассировка не регистрируется, а компилятор не выполняет соответствующую оптимизацию.
Изменим функцию format
в строках 9–12 примера для анализа отчета о профилировании следующим образом:
local function format(a)
local nstr = string.format("%sa", tostring(a))
return nstr
end
Теперь отчет о профилировании будет выглядеть намного лучше:
ALLOCATIONS
@format_concat.lua:10: 109 events +2112 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
INTERNAL: 3 events +1206 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 112 events +0 bytes -2460 bytes
Overrides:
@format_concat.lua:0
@format_concat.lua:10
INTERNAL
HEAP SUMMARY:
INTERNAL holds 1144 bytes: 3 allocs, 1 frees
@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees
Сводка изменений в динамической памяти и параметр –leak-only
Эта функциональная возможность появилась в версии 2.8.1.
В конце каждого отчета приводится раздел HEAP SUMMARY (сводка изменений в динамической памяти). Этот раздел выглядит так:
@<имя_файла>:<номер_строки> holds <количество_доступных_байтов> bytes: <количество_событий_аллокации> allocs, <количество_событий_деаллокации> frees
Иногда программа может вызывать множество событий деаллокации. В этом случае раздел DEALLOCATION сильно увеличится и отчет будет сложно читать. Чтобы уменьшить количество выводимых данных, запустите парсинг с дополнительным параметром --leak-only
. Например, так:
$ tarantool -e 'require("memprof")(arg)' - --leak-only memprof_new.bin
При использовании параметра --leak-only
выводится только раздел HEAP SUMMARY.
Работа с профилировщиком состоит из двух этапов:
- События аллокации, реаллокации и деаллокации в Lua собираются в бинарный профиль (далее по тексту — бинарный профиль памяти или просто бинарный профиль).
- Выполняется парсинг собранного бинарного профиля. В результате формируется отчет о профилировании в удобном для чтения формате.
Сбор бинарного профиля
Чтобы сформировать бинарный профиль для определенного участка кода на Lua, вставьте этот участок кода между функциями misc.memprof.start()
и misc.memprof.stop()
, а затем выполните его в Tarantool.
Для наглядности ниже приведен фрагмент кода на Lua под названием test.lua
.
1-- Отключение аллокации на трассах
2jit.off()
3local str, err = misc.memprof.start("memprof_new.bin")
4-- Lua не создает стековый фрейм для вызова string.rep,
5-- поэтому все события аллокации
6-- приписываются не функции append(), а родительской области
7local function append(str, rep)
8 return string.rep(str, rep)
9end
10
11local t = {}
12for i = 1, 1e4 do
13 -- table.insert — встроенная функция,
14 -- так что профилировщик включает все соответствующие ей
15 -- события аллокации в отчет по основной части кода
16 table.insert(t,
17 append('q', i)
18 )
19end
20local stp, err = misc.memprof.stop()
В примере test.lua код для запуска профилировщика находится на строке 3:
local str, err = misc.memprof.start(ИМЯ_ФАЙЛА)
ИМЯ_ФАЙЛА
— имя бинарного файла, куда записываются профилируемые события.
Если операция завершается ошибкой, функция misc.memprof.start()
возвращает результат, состоящий из трех частей: nil
; строка с сообщением об ошибке; код ошибки в зависимости от системы. Ошибка может возникнуть, например, когда не открывается файл для записи или профилировщик уже запущен. Если операция выполняется успешно, misc.memprof.start()
возвращает true
.
В примере test.lua код для остановки профилировщика находится на строке 18:
local stp, err = misc.memprof.stop()
Если операция завершается ошибкой, функция misc.memprof.stop()
возвращает результат, состоящий из трех частей: nil
; строка с сообщением об ошибке; код ошибки в зависимости от системы. Ошибка может возникнуть, например, когда закрыт файловый дескриптор или во время составления отчета происходит сбой. Если операция выполняется успешно, misc.memprof.stop()
возвращает true
.
Теперь нужно сгенерировать файл с профилем памяти в бинарном формате. В примере test.lua имя файла — memprof_new.bin
. Выполните код в Tarantool:
$ tarantool test.lua
Tarantool собирает события аллокации в файл memprof_new.bin
, помещает его в рабочую директорию и завершает сеанс.
Пример test.lua также иллюстрирует логику, по которой в некоторых случаях происходит аллокация памяти. Важно понимать эту логику, чтобы читать и анализировать отчеты о профилировании.
- Строка 2: Рекомендуется отключать JIT-компиляцию, вызывая
jit.off()
перед запуском профилировщика. За дополнительными сведениями обратитесь к примечанию о jitoff.
- Строки 6–8: Оптимизация хвостового вызова не создает новый фрейм стека вызовов, поэтому все события аллокации в байт-коде
CALLT/CALLMT
относятся на счет кода, вызывающего эту функцию. Обратите внимание на комментарии перед этими строками.
- Строки 14–16: Как правило, разработчиков несильно интересует информация об аллокации во встроенных функциях LuaJIT. Поэтому если встроенная функция вызывается из функции на Lua, профилировщик собирает все события аллокации для функции на Lua. В противном случае событие относится к функции на C. Обратите внимание на комментарии перед этими строками.
Парсинг бинарного профиля и формирование отчета о профилировании
Получив профиль памяти в двоичном формате, нужно выполнить парсинг, чтобы отчет было удобно читать. Парсинг можно выполнить в Tarantool, воспользовавшись следующей командой (обратите внимание на дефис -
перед именем файла):
$ tarantool -e 'require("memprof")(arg)' - memprof_new.bin
Здесь memprof_new.bin
— бинарный профиль, ранее сгенерированный командой tarantool test.lua
. (Внимание: в версии Tarantool 2.8.1 поведение команды tarantool -e
немного изменилось.)
Tarantool генерирует отчет о профилировании и выводит его в консоль перед закрытием сеанса:
ALLOCATIONS
@test.lua:14: 10000 events +50240518 bytes -0 bytes
@test.lua:9: 1 events +32 bytes -0 bytes
@test.lua:8: 1 events +20 bytes -0 bytes
@test.lua:13: 1 events +24 bytes -0 bytes
REALLOCATIONS
@test.lua:13: 13 events +262216 bytes -131160 bytes
Overrides:
@test.lua:13
@test.lua:14: 11 events +49536 bytes -24768 bytes
Overrides:
@test.lua:14
INTERNAL
INTERNAL: 3 events +8448 bytes -16896 bytes
Overrides:
@test.lua:14
DEALLOCATIONS
INTERNAL: 1723 events +0 bytes -483515 bytes
@test.lua:14: 1 events +0 bytes -32768 bytes
HEAP SUMMARY:
@test.lua:14 holds 50248326 bytes: 10010 allocs, 10 frees
@test.lua:13 holds 131080 bytes: 14 allocs, 13 frees
INTERNAL holds 8448 bytes: 3 allocs, 3 frees
@test.lua:9 holds 32 bytes: 1 allocs, 0 frees
@test.lua:8 holds 20 bytes: 1 allocs, 0 frees
Примечание
В macOS отчет по той же части кода выглядит по-другому, поскольку Tarantool и LuaJIT собраны с поддержкой режима GC64 для macOS.
Рассмотрим структуру отчета. Он состоит из четырех разделов:
- ALLOCATIONS (аллокация)
- REALLOCATIONS (реаллокация)
- DEALLOCATIONS (деаллокация)
- HEAP SUMMARY (cводка изменений в динамической памяти, раздел описан ниже)
Записи в каждом разделе отсортированы в порядке от наиболее до наименее частых событий.
Запись о событии регистрируется в следующем формате:
@<имя_файла>:<номер_строки>: <количество_событий> events +<выделенные_байты> bytes -<освобожденные_байты> bytes
- <имя_файла> — имя файла, содержащего код на Lua.
- <номер_строки> — номер строки, в которой обнаружено событие.
- <количество_событий> — количество событий для этой строки кода.
- +<выделенная_память_в_байтах> bytes — объем выделенной памяти для всех событий в этой строке.
- +<освобожденная_память_в_байтах> bytes — объем освобожденной памяти для всех событий в этой строке.
Метка Overrides
на событии показывает, какое событие аллокации оно замещает.
См. код примера test.lua выше и пояснения в комментариях к нему.
Метка INTERNAL
показывает, что событие произошло во внутренних структурах LuaJIT.
Примечание
Важное примечание о метке INTERNAL
и рекомендации отключать компиляцию JIT (jit.off()
). В текущей версии профилировщика не поддерживается подробное (verbose) описание событий аллокации при трассировке. Если память выделяется во время трассировки, профилировщик не может соотнести события аллокации с соответствующей частью кода. В этом случае профилировщик помечает такие события как INTERNAL
.
Когда компиляция JIT включена, выполняется несколько процессов трассировки. В результате пометку INTERNAL
в отчете о профилировании получают самые разные события: некоторые из них действительно возникают во внутренних структурах LuaJIT, а другие вызваны аллокацией при трассировке.
Вы можете получить более конкретный отчет, в который не входят события аллокации, вызванные JIT-компилятором. Для этого до запуска профилировщика вызовите jit.off(). Чтобы полностью исключить из отчета аллокацию на трассах, удалите предыдущие трассы, вызвав после jit.off()
функцию jit.flush()
.
Отключать компиляцию JIT перед запуском профилировщика рекомендуется, но это не обязательно. Например, в производственной среде без компиляции JIT полное представление об аллокациях памяти получить невозможно. В подобных случаях большая часть событий INTERNAL
, вероятнее всего, происходит при трассировках.
Иногда отчет о профилировании помогает исследовать код на Lua. Однако этот метод подходит не для любого кода, так что рекомендаций на этот счет нет. Посмотрите пример анализа отчета о профилировании, чтобы узнать, как можно использовать отчет для исследования кода.
Больше информации о том, как использовать профилировщик, вы найдете ниже в разделе Вопросы и ответы.
Вопросы и ответы
В этом разделе даются ответы на часто задаваемые вопросы о работе профилировщика.
Вопрос (В): Проверяет ли профилировщик аллокацию в C и коде на C?
Ответ (A): Профилировщик включает в отчет только события выделения памяти Lua-аллокатором. Отчет содержит все события аллокации в Lua, например создание таблиц и строк. Однако профилировщик не отслеживает выделение памяти с помощью malloc()
или действия аллокаторов, не связанных с Lua. Чтобы фиксировать такие события, для отладки можно использовать valgrind
.
В: Почему у меня в отчете о профилировании столько событий аллокации INTERNAL
? Что это значит?
О: Пометка INTERNAL
означает, что событие аллокации/реаллокации/деаллокации связано с внутренними структурами LuaJIT или трассами. Сейчас профилировщик не включает в отчет подробное описание событий аллокации для объектов, создаваемых на трассах. Попробуйте перед запуском профилировщика добавить jit.off().
В: Почему на некоторых событиях аллокации/деаллокации нет метки Overrides
?
О: Вероятно, события связаны с объектами, созданными до запуска профилировщика. Если перед запуском профилировщика добавить вызов collectgarbage()
, то будут учитываться и события, связанные с «мертвыми» объектами: под такие объекты ранее была выделена память, но на момент запуска профилировщика они уже недоступны.
В: Почему некоторые объекты не учитываются при профилировании? Это связано с утечкой памяти?
О: LuaJIT использует инкрементальный сборщик мусора. Когда профилировщик завершает работу, цикл сборки мусора может все еще выполняться. Чтобы обеспечить профилирование «мертвых» объектов, добавьте collectgarbage()
перед командой остановки профилировщика.
В: Можно ли профилировать не только часть кода, а все приложение? Можно ли запустить профилировщик во время работы приложения?
О: Да. Вот пример кода, который можно вставить в консоль Tarantool, когда приложение уже запущено:
1local fiber = require "fiber"
2local log = require "log"
3
4fiber.create(function()
5 fiber.name("memprof")
6
7 collectgarbage() -- Сбор мертвых объектов
8 log.warn("start of profile")
9
10 local st, err = misc.memprof.start(ИМЯ_ФАЙЛА)
11 if not st then
12 log.error("failed to start profiler: %s", err)
13 end
14
15 fiber.sleep(ВРЕМЯ)
16
17 collectgarbage()
18 st, err = misc.memprof.stop()
19
20 if not st then
21 log.error("profiler on stop error: %s", err)
22 end
23
24 log.warn("end of profile")
25end)
Пояснения:
ИМЯ_ФАЙЛА
— имя бинарного файла, куда записываются профилируемые события.
ВРЕМЯ
— продолжительность профилирования в секундах.
Кроме того, вызывать misc.memprof.start()
и misc.memprof.stop()
можно напрямую из консоли.
Пример анализа отчета о профилировании
Ниже приведен код на Lua — файл format_concat.lua
. Этот код будет исследован с применением отчетов о профилировании памяти.
1-- Отключение аллокации на новых трассах
2jit.off()
3
4local function concat(a)
5 local nstr = a.."a"
6 return nstr
7end
8
9local function format(a)
10 local nstr = string.format("%sa", a)
11 return nstr
12end
13
14collectgarbage()
15
16local binfile = "/tmp/memprof_"..(arg[0]):match("([^/]*).lua")..".bin"
17
18local st, err = misc.memprof.start(binfile)
19assert(st, err)
20
21-- Нагрузка
22for i = 1, 10000 do
23 local f = format(i)
24 local c = concat(i)
25end
26collectgarbage()
27
28local st, err = misc.memprof.stop()
29assert(st, err)
30
31os.exit()
Запустив этот код в Tarantool и выполнив последующий парсинг бинарного профиля в /tmp/memprof_format_concat.bin, вы получите такой отчет о профилировании:
ALLOCATIONS
@format_concat.lua:10: 19996 events +624284 bytes -0 bytes
INTERNAL: 1 events +65536 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 19996 events +0 bytes -558778 bytes
Overrides:
@format_concat.lua:10
@format_concat.lua:10: 2 events +0 bytes -98304 bytes
Overrides:
@format_concat.lua:10
HEAP SUMMARY:
INTERNAL holds 65536 bytes: 1 allocs, 0 frees
Отчет может вызвать такие вопросы:
- Почему нет событий по функции
concat()
?
- Почему количество событий — это не целое число?
- Почему в отчете не 10 тысяч событий, а около 20 тысяч?
Во-первых, LuaJIT не создает новую строку, если уже есть строка с такой же нагрузкой (подробнее на сайте lua-users.org/wiki). Это называется интернированием строк. Иными словами, если строка создана с помощью функции format()
, нет необходимости создавать такую же строку с помощью функции concat()
— LuaJIT будет использовать предыдущую.
По этой же причине количество событий аллокации — это не целое число, как можно было бы ожидать при использовании оператора цикла for i = 1, 10000...
. Некоторые строки Tarantool создает для внутренних нужд и встроенных модулей, поэтому часть строк уже существует.
Но откуда столько событий аллокации? Их почти в 2 раза больше, чем можно было бы ожидать. Это происходит потому, что встроенная функция string.format()
каждый раз создает дополнительную строку для идентификатора %s
. То есть в каждой итерации регистрируются два события аллокации: для tostring(i)
и для string.format("%sa", string_i_value)
. Добавив строку local _ = tostring(i)
между строками 22 и 23, вы увидите разницу в поведении.
Чтобы профилировать только функцию concat()
, закомментируйте строку 23 (local f = format(i)
) и запустите профилировщик. Теперь результат будет такой:
ALLOCATIONS
@format_concat.lua:5: 10000 events +284411 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 10000 events +0 bytes -218905 bytes
Overrides:
@format_concat.lua:5
@format_concat.lua:5: 1 events +0 bytes -32768 bytes
HEAP SUMMARY:
@format_concat.lua:5 holds 65536 bytes: 10000 allocs, 9999 frees
В: Что изменится, если включить компиляцию JIT?
О: Закомментируйте вторую строку (jit.off()
) в коде и запустите профилировщик. Теперь в отчете только 56 событий. Остальные события связаны с JIT (см. также соответствующую задачу на GitHub):
ALLOCATIONS
@format_concat.lua:5: 56 events +1112 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
INTERNAL: 2 events +382 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 58 events +0 bytes -1164 bytes
Overrides:
@format_concat.lua:5
INTERNAL
HEAP SUMMARY:
@format_concat.lua:0 holds 640 bytes: 4 allocs, 0 frees
INTERNAL holds 360 bytes: 2 allocs, 1 frees
Так произошло потому, что трассировка была скомпилирована после 56 итераций (это значение параметра компилятора hotloop
по умолчанию). Затем JIT-компилятор удалил из трассировки неиспользуемую переменную c
, а вместе с ней и неиспользуемый код функции concat()
.
Теперь включите компиляцию JIT и запустите профилирование только для функции format()
. Для этого закомментируйте строки 2 и 24 (jit.off()
и local c = concat(i)
), раскомментируйте строку 23 (local f = format(i)
) и вызовите профилировщик. Результат будет такой:
ALLOCATIONS
@format_concat.lua:10: 19996 events +624284 bytes -0 bytes
INTERNAL: 4 events +66928 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 19997 events +0 bytes -559034 bytes
Overrides:
@format_concat.lua:0
@format_concat.lua:10
@format_concat.lua:10: 2 events +0 bytes -98304 bytes
Overrides:
@format_concat.lua:10
HEAP SUMMARY:
INTERNAL holds 66928 bytes: 4 allocs, 0 frees
@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees
В: Откуда так много событий аллокации по сравнению с concat()
?
О: Ответ прост: LuaJIT еще не скомпилировал функцию string.format()
с идентификатором %s
. Поэтому трассировка не регистрируется, а компилятор не выполняет соответствующую оптимизацию.
Изменим функцию format
в строках 9–12 примера для анализа отчета о профилировании следующим образом:
local function format(a)
local nstr = string.format("%sa", tostring(a))
return nstr
end
Теперь отчет о профилировании будет выглядеть намного лучше:
ALLOCATIONS
@format_concat.lua:10: 109 events +2112 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
INTERNAL: 3 events +1206 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 112 events +0 bytes -2460 bytes
Overrides:
@format_concat.lua:0
@format_concat.lua:10
INTERNAL
HEAP SUMMARY:
INTERNAL holds 1144 bytes: 3 allocs, 1 frees
@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees
Сводка изменений в динамической памяти и параметр –leak-only
Эта функциональная возможность появилась в версии 2.8.1.
В конце каждого отчета приводится раздел HEAP SUMMARY (сводка изменений в динамической памяти). Этот раздел выглядит так:
@<имя_файла>:<номер_строки> holds <количество_доступных_байтов> bytes: <количество_событий_аллокации> allocs, <количество_событий_деаллокации> frees
Иногда программа может вызывать множество событий деаллокации. В этом случае раздел DEALLOCATION сильно увеличится и отчет будет сложно читать. Чтобы уменьшить количество выводимых данных, запустите парсинг с дополнительным параметром --leak-only
. Например, так:
$ tarantool -e 'require("memprof")(arg)' - --leak-only memprof_new.bin
При использовании параметра --leak-only
выводится только раздел HEAP SUMMARY.
Чтобы сформировать бинарный профиль для определенного участка кода на Lua, вставьте этот участок кода между функциями misc.memprof.start()
и misc.memprof.stop()
, а затем выполните его в Tarantool.
Для наглядности ниже приведен фрагмент кода на Lua под названием test.lua
.
1-- Отключение аллокации на трассах
2jit.off()
3local str, err = misc.memprof.start("memprof_new.bin")
4-- Lua не создает стековый фрейм для вызова string.rep,
5-- поэтому все события аллокации
6-- приписываются не функции append(), а родительской области
7local function append(str, rep)
8 return string.rep(str, rep)
9end
10
11local t = {}
12for i = 1, 1e4 do
13 -- table.insert — встроенная функция,
14 -- так что профилировщик включает все соответствующие ей
15 -- события аллокации в отчет по основной части кода
16 table.insert(t,
17 append('q', i)
18 )
19end
20local stp, err = misc.memprof.stop()
В примере test.lua код для запуска профилировщика находится на строке 3:
local str, err = misc.memprof.start(ИМЯ_ФАЙЛА)
ИМЯ_ФАЙЛА
— имя бинарного файла, куда записываются профилируемые события.
Если операция завершается ошибкой, функция misc.memprof.start()
возвращает результат, состоящий из трех частей: nil
; строка с сообщением об ошибке; код ошибки в зависимости от системы. Ошибка может возникнуть, например, когда не открывается файл для записи или профилировщик уже запущен. Если операция выполняется успешно, misc.memprof.start()
возвращает true
.
В примере test.lua код для остановки профилировщика находится на строке 18:
local stp, err = misc.memprof.stop()
Если операция завершается ошибкой, функция misc.memprof.stop()
возвращает результат, состоящий из трех частей: nil
; строка с сообщением об ошибке; код ошибки в зависимости от системы. Ошибка может возникнуть, например, когда закрыт файловый дескриптор или во время составления отчета происходит сбой. Если операция выполняется успешно, misc.memprof.stop()
возвращает true
.
Теперь нужно сгенерировать файл с профилем памяти в бинарном формате. В примере test.lua имя файла — memprof_new.bin
. Выполните код в Tarantool:
$ tarantool test.lua
Tarantool собирает события аллокации в файл memprof_new.bin
, помещает его в рабочую директорию и завершает сеанс.
Пример test.lua также иллюстрирует логику, по которой в некоторых случаях происходит аллокация памяти. Важно понимать эту логику, чтобы читать и анализировать отчеты о профилировании.
- Строка 2: Рекомендуется отключать JIT-компиляцию, вызывая
jit.off()
перед запуском профилировщика. За дополнительными сведениями обратитесь к примечанию о jitoff. - Строки 6–8: Оптимизация хвостового вызова не создает новый фрейм стека вызовов, поэтому все события аллокации в байт-коде
CALLT/CALLMT
относятся на счет кода, вызывающего эту функцию. Обратите внимание на комментарии перед этими строками. - Строки 14–16: Как правило, разработчиков несильно интересует информация об аллокации во встроенных функциях LuaJIT. Поэтому если встроенная функция вызывается из функции на Lua, профилировщик собирает все события аллокации для функции на Lua. В противном случае событие относится к функции на C. Обратите внимание на комментарии перед этими строками.
Парсинг бинарного профиля и формирование отчета о профилировании
Получив профиль памяти в двоичном формате, нужно выполнить парсинг, чтобы отчет было удобно читать. Парсинг можно выполнить в Tarantool, воспользовавшись следующей командой (обратите внимание на дефис -
перед именем файла):
$ tarantool -e 'require("memprof")(arg)' - memprof_new.bin
Здесь memprof_new.bin
— бинарный профиль, ранее сгенерированный командой tarantool test.lua
. (Внимание: в версии Tarantool 2.8.1 поведение команды tarantool -e
немного изменилось.)
Tarantool генерирует отчет о профилировании и выводит его в консоль перед закрытием сеанса:
ALLOCATIONS
@test.lua:14: 10000 events +50240518 bytes -0 bytes
@test.lua:9: 1 events +32 bytes -0 bytes
@test.lua:8: 1 events +20 bytes -0 bytes
@test.lua:13: 1 events +24 bytes -0 bytes
REALLOCATIONS
@test.lua:13: 13 events +262216 bytes -131160 bytes
Overrides:
@test.lua:13
@test.lua:14: 11 events +49536 bytes -24768 bytes
Overrides:
@test.lua:14
INTERNAL
INTERNAL: 3 events +8448 bytes -16896 bytes
Overrides:
@test.lua:14
DEALLOCATIONS
INTERNAL: 1723 events +0 bytes -483515 bytes
@test.lua:14: 1 events +0 bytes -32768 bytes
HEAP SUMMARY:
@test.lua:14 holds 50248326 bytes: 10010 allocs, 10 frees
@test.lua:13 holds 131080 bytes: 14 allocs, 13 frees
INTERNAL holds 8448 bytes: 3 allocs, 3 frees
@test.lua:9 holds 32 bytes: 1 allocs, 0 frees
@test.lua:8 holds 20 bytes: 1 allocs, 0 frees
Примечание
В macOS отчет по той же части кода выглядит по-другому, поскольку Tarantool и LuaJIT собраны с поддержкой режима GC64 для macOS.
Рассмотрим структуру отчета. Он состоит из четырех разделов:
- ALLOCATIONS (аллокация)
- REALLOCATIONS (реаллокация)
- DEALLOCATIONS (деаллокация)
- HEAP SUMMARY (cводка изменений в динамической памяти, раздел описан ниже)
Записи в каждом разделе отсортированы в порядке от наиболее до наименее частых событий.
Запись о событии регистрируется в следующем формате:
@<имя_файла>:<номер_строки>: <количество_событий> events +<выделенные_байты> bytes -<освобожденные_байты> bytes
- <имя_файла> — имя файла, содержащего код на Lua.
- <номер_строки> — номер строки, в которой обнаружено событие.
- <количество_событий> — количество событий для этой строки кода.
- +<выделенная_память_в_байтах> bytes — объем выделенной памяти для всех событий в этой строке.
- +<освобожденная_память_в_байтах> bytes — объем освобожденной памяти для всех событий в этой строке.
Метка Overrides
на событии показывает, какое событие аллокации оно замещает.
См. код примера test.lua выше и пояснения в комментариях к нему.
Метка INTERNAL
показывает, что событие произошло во внутренних структурах LuaJIT.
Примечание
Важное примечание о метке INTERNAL
и рекомендации отключать компиляцию JIT (jit.off()
). В текущей версии профилировщика не поддерживается подробное (verbose) описание событий аллокации при трассировке. Если память выделяется во время трассировки, профилировщик не может соотнести события аллокации с соответствующей частью кода. В этом случае профилировщик помечает такие события как INTERNAL
.
Когда компиляция JIT включена, выполняется несколько процессов трассировки. В результате пометку INTERNAL
в отчете о профилировании получают самые разные события: некоторые из них действительно возникают во внутренних структурах LuaJIT, а другие вызваны аллокацией при трассировке.
Вы можете получить более конкретный отчет, в который не входят события аллокации, вызванные JIT-компилятором. Для этого до запуска профилировщика вызовите jit.off(). Чтобы полностью исключить из отчета аллокацию на трассах, удалите предыдущие трассы, вызвав после jit.off()
функцию jit.flush()
.
Отключать компиляцию JIT перед запуском профилировщика рекомендуется, но это не обязательно. Например, в производственной среде без компиляции JIT полное представление об аллокациях памяти получить невозможно. В подобных случаях большая часть событий INTERNAL
, вероятнее всего, происходит при трассировках.
Иногда отчет о профилировании помогает исследовать код на Lua. Однако этот метод подходит не для любого кода, так что рекомендаций на этот счет нет. Посмотрите пример анализа отчета о профилировании, чтобы узнать, как можно использовать отчет для исследования кода.
Больше информации о том, как использовать профилировщик, вы найдете ниже в разделе Вопросы и ответы.
Вопросы и ответы
В этом разделе даются ответы на часто задаваемые вопросы о работе профилировщика.
Вопрос (В): Проверяет ли профилировщик аллокацию в C и коде на C?
Ответ (A): Профилировщик включает в отчет только события выделения памяти Lua-аллокатором. Отчет содержит все события аллокации в Lua, например создание таблиц и строк. Однако профилировщик не отслеживает выделение памяти с помощью malloc()
или действия аллокаторов, не связанных с Lua. Чтобы фиксировать такие события, для отладки можно использовать valgrind
.
В: Почему у меня в отчете о профилировании столько событий аллокации INTERNAL
? Что это значит?
О: Пометка INTERNAL
означает, что событие аллокации/реаллокации/деаллокации связано с внутренними структурами LuaJIT или трассами. Сейчас профилировщик не включает в отчет подробное описание событий аллокации для объектов, создаваемых на трассах. Попробуйте перед запуском профилировщика добавить jit.off().
В: Почему на некоторых событиях аллокации/деаллокации нет метки Overrides
?
О: Вероятно, события связаны с объектами, созданными до запуска профилировщика. Если перед запуском профилировщика добавить вызов collectgarbage()
, то будут учитываться и события, связанные с «мертвыми» объектами: под такие объекты ранее была выделена память, но на момент запуска профилировщика они уже недоступны.
В: Почему некоторые объекты не учитываются при профилировании? Это связано с утечкой памяти?
О: LuaJIT использует инкрементальный сборщик мусора. Когда профилировщик завершает работу, цикл сборки мусора может все еще выполняться. Чтобы обеспечить профилирование «мертвых» объектов, добавьте collectgarbage()
перед командой остановки профилировщика.
В: Можно ли профилировать не только часть кода, а все приложение? Можно ли запустить профилировщик во время работы приложения?
О: Да. Вот пример кода, который можно вставить в консоль Tarantool, когда приложение уже запущено:
1local fiber = require "fiber"
2local log = require "log"
3
4fiber.create(function()
5 fiber.name("memprof")
6
7 collectgarbage() -- Сбор мертвых объектов
8 log.warn("start of profile")
9
10 local st, err = misc.memprof.start(ИМЯ_ФАЙЛА)
11 if not st then
12 log.error("failed to start profiler: %s", err)
13 end
14
15 fiber.sleep(ВРЕМЯ)
16
17 collectgarbage()
18 st, err = misc.memprof.stop()
19
20 if not st then
21 log.error("profiler on stop error: %s", err)
22 end
23
24 log.warn("end of profile")
25end)
Пояснения:
ИМЯ_ФАЙЛА
— имя бинарного файла, куда записываются профилируемые события.
ВРЕМЯ
— продолжительность профилирования в секундах.
Кроме того, вызывать misc.memprof.start()
и misc.memprof.stop()
можно напрямую из консоли.
Пример анализа отчета о профилировании
Ниже приведен код на Lua — файл format_concat.lua
. Этот код будет исследован с применением отчетов о профилировании памяти.
1-- Отключение аллокации на новых трассах
2jit.off()
3
4local function concat(a)
5 local nstr = a.."a"
6 return nstr
7end
8
9local function format(a)
10 local nstr = string.format("%sa", a)
11 return nstr
12end
13
14collectgarbage()
15
16local binfile = "/tmp/memprof_"..(arg[0]):match("([^/]*).lua")..".bin"
17
18local st, err = misc.memprof.start(binfile)
19assert(st, err)
20
21-- Нагрузка
22for i = 1, 10000 do
23 local f = format(i)
24 local c = concat(i)
25end
26collectgarbage()
27
28local st, err = misc.memprof.stop()
29assert(st, err)
30
31os.exit()
Запустив этот код в Tarantool и выполнив последующий парсинг бинарного профиля в /tmp/memprof_format_concat.bin, вы получите такой отчет о профилировании:
ALLOCATIONS
@format_concat.lua:10: 19996 events +624284 bytes -0 bytes
INTERNAL: 1 events +65536 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 19996 events +0 bytes -558778 bytes
Overrides:
@format_concat.lua:10
@format_concat.lua:10: 2 events +0 bytes -98304 bytes
Overrides:
@format_concat.lua:10
HEAP SUMMARY:
INTERNAL holds 65536 bytes: 1 allocs, 0 frees
Отчет может вызвать такие вопросы:
- Почему нет событий по функции
concat()
?
- Почему количество событий — это не целое число?
- Почему в отчете не 10 тысяч событий, а около 20 тысяч?
Во-первых, LuaJIT не создает новую строку, если уже есть строка с такой же нагрузкой (подробнее на сайте lua-users.org/wiki). Это называется интернированием строк. Иными словами, если строка создана с помощью функции format()
, нет необходимости создавать такую же строку с помощью функции concat()
— LuaJIT будет использовать предыдущую.
По этой же причине количество событий аллокации — это не целое число, как можно было бы ожидать при использовании оператора цикла for i = 1, 10000...
. Некоторые строки Tarantool создает для внутренних нужд и встроенных модулей, поэтому часть строк уже существует.
Но откуда столько событий аллокации? Их почти в 2 раза больше, чем можно было бы ожидать. Это происходит потому, что встроенная функция string.format()
каждый раз создает дополнительную строку для идентификатора %s
. То есть в каждой итерации регистрируются два события аллокации: для tostring(i)
и для string.format("%sa", string_i_value)
. Добавив строку local _ = tostring(i)
между строками 22 и 23, вы увидите разницу в поведении.
Чтобы профилировать только функцию concat()
, закомментируйте строку 23 (local f = format(i)
) и запустите профилировщик. Теперь результат будет такой:
ALLOCATIONS
@format_concat.lua:5: 10000 events +284411 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 10000 events +0 bytes -218905 bytes
Overrides:
@format_concat.lua:5
@format_concat.lua:5: 1 events +0 bytes -32768 bytes
HEAP SUMMARY:
@format_concat.lua:5 holds 65536 bytes: 10000 allocs, 9999 frees
В: Что изменится, если включить компиляцию JIT?
О: Закомментируйте вторую строку (jit.off()
) в коде и запустите профилировщик. Теперь в отчете только 56 событий. Остальные события связаны с JIT (см. также соответствующую задачу на GitHub):
ALLOCATIONS
@format_concat.lua:5: 56 events +1112 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
INTERNAL: 2 events +382 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 58 events +0 bytes -1164 bytes
Overrides:
@format_concat.lua:5
INTERNAL
HEAP SUMMARY:
@format_concat.lua:0 holds 640 bytes: 4 allocs, 0 frees
INTERNAL holds 360 bytes: 2 allocs, 1 frees
Так произошло потому, что трассировка была скомпилирована после 56 итераций (это значение параметра компилятора hotloop
по умолчанию). Затем JIT-компилятор удалил из трассировки неиспользуемую переменную c
, а вместе с ней и неиспользуемый код функции concat()
.
Теперь включите компиляцию JIT и запустите профилирование только для функции format()
. Для этого закомментируйте строки 2 и 24 (jit.off()
и local c = concat(i)
), раскомментируйте строку 23 (local f = format(i)
) и вызовите профилировщик. Результат будет такой:
ALLOCATIONS
@format_concat.lua:10: 19996 events +624284 bytes -0 bytes
INTERNAL: 4 events +66928 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 19997 events +0 bytes -559034 bytes
Overrides:
@format_concat.lua:0
@format_concat.lua:10
@format_concat.lua:10: 2 events +0 bytes -98304 bytes
Overrides:
@format_concat.lua:10
HEAP SUMMARY:
INTERNAL holds 66928 bytes: 4 allocs, 0 frees
@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees
В: Откуда так много событий аллокации по сравнению с concat()
?
О: Ответ прост: LuaJIT еще не скомпилировал функцию string.format()
с идентификатором %s
. Поэтому трассировка не регистрируется, а компилятор не выполняет соответствующую оптимизацию.
Изменим функцию format
в строках 9–12 примера для анализа отчета о профилировании следующим образом:
local function format(a)
local nstr = string.format("%sa", tostring(a))
return nstr
end
Теперь отчет о профилировании будет выглядеть намного лучше:
ALLOCATIONS
@format_concat.lua:10: 109 events +2112 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
INTERNAL: 3 events +1206 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 112 events +0 bytes -2460 bytes
Overrides:
@format_concat.lua:0
@format_concat.lua:10
INTERNAL
HEAP SUMMARY:
INTERNAL holds 1144 bytes: 3 allocs, 1 frees
@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees
Сводка изменений в динамической памяти и параметр –leak-only
Эта функциональная возможность появилась в версии 2.8.1.
В конце каждого отчета приводится раздел HEAP SUMMARY (сводка изменений в динамической памяти). Этот раздел выглядит так:
@<имя_файла>:<номер_строки> holds <количество_доступных_байтов> bytes: <количество_событий_аллокации> allocs, <количество_событий_деаллокации> frees
Иногда программа может вызывать множество событий деаллокации. В этом случае раздел DEALLOCATION сильно увеличится и отчет будет сложно читать. Чтобы уменьшить количество выводимых данных, запустите парсинг с дополнительным параметром --leak-only
. Например, так:
$ tarantool -e 'require("memprof")(arg)' - --leak-only memprof_new.bin
При использовании параметра --leak-only
выводится только раздел HEAP SUMMARY.
Получив профиль памяти в двоичном формате, нужно выполнить парсинг, чтобы отчет было удобно читать. Парсинг можно выполнить в Tarantool, воспользовавшись следующей командой (обратите внимание на дефис -
перед именем файла):
$ tarantool -e 'require("memprof")(arg)' - memprof_new.bin
Здесь memprof_new.bin
— бинарный профиль, ранее сгенерированный командой tarantool test.lua
. (Внимание: в версии Tarantool 2.8.1 поведение команды tarantool -e
немного изменилось.)
Tarantool генерирует отчет о профилировании и выводит его в консоль перед закрытием сеанса:
ALLOCATIONS
@test.lua:14: 10000 events +50240518 bytes -0 bytes
@test.lua:9: 1 events +32 bytes -0 bytes
@test.lua:8: 1 events +20 bytes -0 bytes
@test.lua:13: 1 events +24 bytes -0 bytes
REALLOCATIONS
@test.lua:13: 13 events +262216 bytes -131160 bytes
Overrides:
@test.lua:13
@test.lua:14: 11 events +49536 bytes -24768 bytes
Overrides:
@test.lua:14
INTERNAL
INTERNAL: 3 events +8448 bytes -16896 bytes
Overrides:
@test.lua:14
DEALLOCATIONS
INTERNAL: 1723 events +0 bytes -483515 bytes
@test.lua:14: 1 events +0 bytes -32768 bytes
HEAP SUMMARY:
@test.lua:14 holds 50248326 bytes: 10010 allocs, 10 frees
@test.lua:13 holds 131080 bytes: 14 allocs, 13 frees
INTERNAL holds 8448 bytes: 3 allocs, 3 frees
@test.lua:9 holds 32 bytes: 1 allocs, 0 frees
@test.lua:8 holds 20 bytes: 1 allocs, 0 frees
Примечание
В macOS отчет по той же части кода выглядит по-другому, поскольку Tarantool и LuaJIT собраны с поддержкой режима GC64 для macOS.
Рассмотрим структуру отчета. Он состоит из четырех разделов:
- ALLOCATIONS (аллокация)
- REALLOCATIONS (реаллокация)
- DEALLOCATIONS (деаллокация)
- HEAP SUMMARY (cводка изменений в динамической памяти, раздел описан ниже)
Записи в каждом разделе отсортированы в порядке от наиболее до наименее частых событий.
Запись о событии регистрируется в следующем формате:
@<имя_файла>:<номер_строки>: <количество_событий> events +<выделенные_байты> bytes -<освобожденные_байты> bytes
- <имя_файла> — имя файла, содержащего код на Lua.
- <номер_строки> — номер строки, в которой обнаружено событие.
- <количество_событий> — количество событий для этой строки кода.
- +<выделенная_память_в_байтах> bytes — объем выделенной памяти для всех событий в этой строке.
- +<освобожденная_память_в_байтах> bytes — объем освобожденной памяти для всех событий в этой строке.
Метка Overrides
на событии показывает, какое событие аллокации оно замещает.
См. код примера test.lua выше и пояснения в комментариях к нему.
Метка INTERNAL
показывает, что событие произошло во внутренних структурах LuaJIT.
Примечание
Важное примечание о метке INTERNAL
и рекомендации отключать компиляцию JIT (jit.off()
). В текущей версии профилировщика не поддерживается подробное (verbose) описание событий аллокации при трассировке. Если память выделяется во время трассировки, профилировщик не может соотнести события аллокации с соответствующей частью кода. В этом случае профилировщик помечает такие события как INTERNAL
.
Когда компиляция JIT включена, выполняется несколько процессов трассировки. В результате пометку INTERNAL
в отчете о профилировании получают самые разные события: некоторые из них действительно возникают во внутренних структурах LuaJIT, а другие вызваны аллокацией при трассировке.
Вы можете получить более конкретный отчет, в который не входят события аллокации, вызванные JIT-компилятором. Для этого до запуска профилировщика вызовите jit.off(). Чтобы полностью исключить из отчета аллокацию на трассах, удалите предыдущие трассы, вызвав после jit.off()
функцию jit.flush()
.
Отключать компиляцию JIT перед запуском профилировщика рекомендуется, но это не обязательно. Например, в производственной среде без компиляции JIT полное представление об аллокациях памяти получить невозможно. В подобных случаях большая часть событий INTERNAL
, вероятнее всего, происходит при трассировках.
Иногда отчет о профилировании помогает исследовать код на Lua. Однако этот метод подходит не для любого кода, так что рекомендаций на этот счет нет. Посмотрите пример анализа отчета о профилировании, чтобы узнать, как можно использовать отчет для исследования кода.
Больше информации о том, как использовать профилировщик, вы найдете ниже в разделе Вопросы и ответы.
Вопросы и ответы
В этом разделе даются ответы на часто задаваемые вопросы о работе профилировщика.
Вопрос (В): Проверяет ли профилировщик аллокацию в C и коде на C?
Ответ (A): Профилировщик включает в отчет только события выделения памяти Lua-аллокатором. Отчет содержит все события аллокации в Lua, например создание таблиц и строк. Однако профилировщик не отслеживает выделение памяти с помощью malloc()
или действия аллокаторов, не связанных с Lua. Чтобы фиксировать такие события, для отладки можно использовать valgrind
.
В: Почему у меня в отчете о профилировании столько событий аллокации INTERNAL
? Что это значит?
О: Пометка INTERNAL
означает, что событие аллокации/реаллокации/деаллокации связано с внутренними структурами LuaJIT или трассами. Сейчас профилировщик не включает в отчет подробное описание событий аллокации для объектов, создаваемых на трассах. Попробуйте перед запуском профилировщика добавить jit.off().
В: Почему на некоторых событиях аллокации/деаллокации нет метки Overrides
?
О: Вероятно, события связаны с объектами, созданными до запуска профилировщика. Если перед запуском профилировщика добавить вызов collectgarbage()
, то будут учитываться и события, связанные с «мертвыми» объектами: под такие объекты ранее была выделена память, но на момент запуска профилировщика они уже недоступны.
В: Почему некоторые объекты не учитываются при профилировании? Это связано с утечкой памяти?
О: LuaJIT использует инкрементальный сборщик мусора. Когда профилировщик завершает работу, цикл сборки мусора может все еще выполняться. Чтобы обеспечить профилирование «мертвых» объектов, добавьте collectgarbage()
перед командой остановки профилировщика.
В: Можно ли профилировать не только часть кода, а все приложение? Можно ли запустить профилировщик во время работы приложения?
О: Да. Вот пример кода, который можно вставить в консоль Tarantool, когда приложение уже запущено:
1local fiber = require "fiber"
2local log = require "log"
3
4fiber.create(function()
5 fiber.name("memprof")
6
7 collectgarbage() -- Сбор мертвых объектов
8 log.warn("start of profile")
9
10 local st, err = misc.memprof.start(ИМЯ_ФАЙЛА)
11 if not st then
12 log.error("failed to start profiler: %s", err)
13 end
14
15 fiber.sleep(ВРЕМЯ)
16
17 collectgarbage()
18 st, err = misc.memprof.stop()
19
20 if not st then
21 log.error("profiler on stop error: %s", err)
22 end
23
24 log.warn("end of profile")
25end)
Пояснения:
ИМЯ_ФАЙЛА
— имя бинарного файла, куда записываются профилируемые события.
ВРЕМЯ
— продолжительность профилирования в секундах.
Кроме того, вызывать misc.memprof.start()
и misc.memprof.stop()
можно напрямую из консоли.
Пример анализа отчета о профилировании
Ниже приведен код на Lua — файл format_concat.lua
. Этот код будет исследован с применением отчетов о профилировании памяти.
1-- Отключение аллокации на новых трассах
2jit.off()
3
4local function concat(a)
5 local nstr = a.."a"
6 return nstr
7end
8
9local function format(a)
10 local nstr = string.format("%sa", a)
11 return nstr
12end
13
14collectgarbage()
15
16local binfile = "/tmp/memprof_"..(arg[0]):match("([^/]*).lua")..".bin"
17
18local st, err = misc.memprof.start(binfile)
19assert(st, err)
20
21-- Нагрузка
22for i = 1, 10000 do
23 local f = format(i)
24 local c = concat(i)
25end
26collectgarbage()
27
28local st, err = misc.memprof.stop()
29assert(st, err)
30
31os.exit()
Запустив этот код в Tarantool и выполнив последующий парсинг бинарного профиля в /tmp/memprof_format_concat.bin, вы получите такой отчет о профилировании:
ALLOCATIONS
@format_concat.lua:10: 19996 events +624284 bytes -0 bytes
INTERNAL: 1 events +65536 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 19996 events +0 bytes -558778 bytes
Overrides:
@format_concat.lua:10
@format_concat.lua:10: 2 events +0 bytes -98304 bytes
Overrides:
@format_concat.lua:10
HEAP SUMMARY:
INTERNAL holds 65536 bytes: 1 allocs, 0 frees
Отчет может вызвать такие вопросы:
- Почему нет событий по функции
concat()
?
- Почему количество событий — это не целое число?
- Почему в отчете не 10 тысяч событий, а около 20 тысяч?
Во-первых, LuaJIT не создает новую строку, если уже есть строка с такой же нагрузкой (подробнее на сайте lua-users.org/wiki). Это называется интернированием строк. Иными словами, если строка создана с помощью функции format()
, нет необходимости создавать такую же строку с помощью функции concat()
— LuaJIT будет использовать предыдущую.
По этой же причине количество событий аллокации — это не целое число, как можно было бы ожидать при использовании оператора цикла for i = 1, 10000...
. Некоторые строки Tarantool создает для внутренних нужд и встроенных модулей, поэтому часть строк уже существует.
Но откуда столько событий аллокации? Их почти в 2 раза больше, чем можно было бы ожидать. Это происходит потому, что встроенная функция string.format()
каждый раз создает дополнительную строку для идентификатора %s
. То есть в каждой итерации регистрируются два события аллокации: для tostring(i)
и для string.format("%sa", string_i_value)
. Добавив строку local _ = tostring(i)
между строками 22 и 23, вы увидите разницу в поведении.
Чтобы профилировать только функцию concat()
, закомментируйте строку 23 (local f = format(i)
) и запустите профилировщик. Теперь результат будет такой:
ALLOCATIONS
@format_concat.lua:5: 10000 events +284411 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 10000 events +0 bytes -218905 bytes
Overrides:
@format_concat.lua:5
@format_concat.lua:5: 1 events +0 bytes -32768 bytes
HEAP SUMMARY:
@format_concat.lua:5 holds 65536 bytes: 10000 allocs, 9999 frees
В: Что изменится, если включить компиляцию JIT?
О: Закомментируйте вторую строку (jit.off()
) в коде и запустите профилировщик. Теперь в отчете только 56 событий. Остальные события связаны с JIT (см. также соответствующую задачу на GitHub):
ALLOCATIONS
@format_concat.lua:5: 56 events +1112 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
INTERNAL: 2 events +382 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 58 events +0 bytes -1164 bytes
Overrides:
@format_concat.lua:5
INTERNAL
HEAP SUMMARY:
@format_concat.lua:0 holds 640 bytes: 4 allocs, 0 frees
INTERNAL holds 360 bytes: 2 allocs, 1 frees
Так произошло потому, что трассировка была скомпилирована после 56 итераций (это значение параметра компилятора hotloop
по умолчанию). Затем JIT-компилятор удалил из трассировки неиспользуемую переменную c
, а вместе с ней и неиспользуемый код функции concat()
.
Теперь включите компиляцию JIT и запустите профилирование только для функции format()
. Для этого закомментируйте строки 2 и 24 (jit.off()
и local c = concat(i)
), раскомментируйте строку 23 (local f = format(i)
) и вызовите профилировщик. Результат будет такой:
ALLOCATIONS
@format_concat.lua:10: 19996 events +624284 bytes -0 bytes
INTERNAL: 4 events +66928 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 19997 events +0 bytes -559034 bytes
Overrides:
@format_concat.lua:0
@format_concat.lua:10
@format_concat.lua:10: 2 events +0 bytes -98304 bytes
Overrides:
@format_concat.lua:10
HEAP SUMMARY:
INTERNAL holds 66928 bytes: 4 allocs, 0 frees
@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees
В: Откуда так много событий аллокации по сравнению с concat()
?
О: Ответ прост: LuaJIT еще не скомпилировал функцию string.format()
с идентификатором %s
. Поэтому трассировка не регистрируется, а компилятор не выполняет соответствующую оптимизацию.
Изменим функцию format
в строках 9–12 примера для анализа отчета о профилировании следующим образом:
local function format(a)
local nstr = string.format("%sa", tostring(a))
return nstr
end
Теперь отчет о профилировании будет выглядеть намного лучше:
ALLOCATIONS
@format_concat.lua:10: 109 events +2112 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
INTERNAL: 3 events +1206 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 112 events +0 bytes -2460 bytes
Overrides:
@format_concat.lua:0
@format_concat.lua:10
INTERNAL
HEAP SUMMARY:
INTERNAL holds 1144 bytes: 3 allocs, 1 frees
@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees
Сводка изменений в динамической памяти и параметр –leak-only
Эта функциональная возможность появилась в версии 2.8.1.
В конце каждого отчета приводится раздел HEAP SUMMARY (сводка изменений в динамической памяти). Этот раздел выглядит так:
@<имя_файла>:<номер_строки> holds <количество_доступных_байтов> bytes: <количество_событий_аллокации> allocs, <количество_событий_деаллокации> frees
Иногда программа может вызывать множество событий деаллокации. В этом случае раздел DEALLOCATION сильно увеличится и отчет будет сложно читать. Чтобы уменьшить количество выводимых данных, запустите парсинг с дополнительным параметром --leak-only
. Например, так:
$ tarantool -e 'require("memprof")(arg)' - --leak-only memprof_new.bin
При использовании параметра --leak-only
выводится только раздел HEAP SUMMARY.
В этом разделе даются ответы на часто задаваемые вопросы о работе профилировщика.
Вопрос (В): Проверяет ли профилировщик аллокацию в C и коде на C?
Ответ (A): Профилировщик включает в отчет только события выделения памяти Lua-аллокатором. Отчет содержит все события аллокации в Lua, например создание таблиц и строк. Однако профилировщик не отслеживает выделение памяти с помощью malloc()
или действия аллокаторов, не связанных с Lua. Чтобы фиксировать такие события, для отладки можно использовать valgrind
.
В: Почему у меня в отчете о профилировании столько событий аллокации INTERNAL
? Что это значит?
О: Пометка INTERNAL
означает, что событие аллокации/реаллокации/деаллокации связано с внутренними структурами LuaJIT или трассами. Сейчас профилировщик не включает в отчет подробное описание событий аллокации для объектов, создаваемых на трассах. Попробуйте перед запуском профилировщика добавить jit.off().
В: Почему на некоторых событиях аллокации/деаллокации нет метки Overrides
?
О: Вероятно, события связаны с объектами, созданными до запуска профилировщика. Если перед запуском профилировщика добавить вызов collectgarbage()
, то будут учитываться и события, связанные с «мертвыми» объектами: под такие объекты ранее была выделена память, но на момент запуска профилировщика они уже недоступны.
В: Почему некоторые объекты не учитываются при профилировании? Это связано с утечкой памяти?
О: LuaJIT использует инкрементальный сборщик мусора. Когда профилировщик завершает работу, цикл сборки мусора может все еще выполняться. Чтобы обеспечить профилирование «мертвых» объектов, добавьте collectgarbage()
перед командой остановки профилировщика.
В: Можно ли профилировать не только часть кода, а все приложение? Можно ли запустить профилировщик во время работы приложения?
О: Да. Вот пример кода, который можно вставить в консоль Tarantool, когда приложение уже запущено:
1local fiber = require "fiber"
2local log = require "log"
3
4fiber.create(function()
5 fiber.name("memprof")
6
7 collectgarbage() -- Сбор мертвых объектов
8 log.warn("start of profile")
9
10 local st, err = misc.memprof.start(ИМЯ_ФАЙЛА)
11 if not st then
12 log.error("failed to start profiler: %s", err)
13 end
14
15 fiber.sleep(ВРЕМЯ)
16
17 collectgarbage()
18 st, err = misc.memprof.stop()
19
20 if not st then
21 log.error("profiler on stop error: %s", err)
22 end
23
24 log.warn("end of profile")
25end)
Пояснения:
ИМЯ_ФАЙЛА
— имя бинарного файла, куда записываются профилируемые события.ВРЕМЯ
— продолжительность профилирования в секундах.
Кроме того, вызывать misc.memprof.start()
и misc.memprof.stop()
можно напрямую из консоли.
Пример анализа отчета о профилировании
Ниже приведен код на Lua — файл format_concat.lua
. Этот код будет исследован с применением отчетов о профилировании памяти.
1-- Отключение аллокации на новых трассах
2jit.off()
3
4local function concat(a)
5 local nstr = a.."a"
6 return nstr
7end
8
9local function format(a)
10 local nstr = string.format("%sa", a)
11 return nstr
12end
13
14collectgarbage()
15
16local binfile = "/tmp/memprof_"..(arg[0]):match("([^/]*).lua")..".bin"
17
18local st, err = misc.memprof.start(binfile)
19assert(st, err)
20
21-- Нагрузка
22for i = 1, 10000 do
23 local f = format(i)
24 local c = concat(i)
25end
26collectgarbage()
27
28local st, err = misc.memprof.stop()
29assert(st, err)
30
31os.exit()
Запустив этот код в Tarantool и выполнив последующий парсинг бинарного профиля в /tmp/memprof_format_concat.bin, вы получите такой отчет о профилировании:
ALLOCATIONS
@format_concat.lua:10: 19996 events +624284 bytes -0 bytes
INTERNAL: 1 events +65536 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 19996 events +0 bytes -558778 bytes
Overrides:
@format_concat.lua:10
@format_concat.lua:10: 2 events +0 bytes -98304 bytes
Overrides:
@format_concat.lua:10
HEAP SUMMARY:
INTERNAL holds 65536 bytes: 1 allocs, 0 frees
Отчет может вызвать такие вопросы:
- Почему нет событий по функции
concat()
?
- Почему количество событий — это не целое число?
- Почему в отчете не 10 тысяч событий, а около 20 тысяч?
Во-первых, LuaJIT не создает новую строку, если уже есть строка с такой же нагрузкой (подробнее на сайте lua-users.org/wiki). Это называется интернированием строк. Иными словами, если строка создана с помощью функции format()
, нет необходимости создавать такую же строку с помощью функции concat()
— LuaJIT будет использовать предыдущую.
По этой же причине количество событий аллокации — это не целое число, как можно было бы ожидать при использовании оператора цикла for i = 1, 10000...
. Некоторые строки Tarantool создает для внутренних нужд и встроенных модулей, поэтому часть строк уже существует.
Но откуда столько событий аллокации? Их почти в 2 раза больше, чем можно было бы ожидать. Это происходит потому, что встроенная функция string.format()
каждый раз создает дополнительную строку для идентификатора %s
. То есть в каждой итерации регистрируются два события аллокации: для tostring(i)
и для string.format("%sa", string_i_value)
. Добавив строку local _ = tostring(i)
между строками 22 и 23, вы увидите разницу в поведении.
Чтобы профилировать только функцию concat()
, закомментируйте строку 23 (local f = format(i)
) и запустите профилировщик. Теперь результат будет такой:
ALLOCATIONS
@format_concat.lua:5: 10000 events +284411 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 10000 events +0 bytes -218905 bytes
Overrides:
@format_concat.lua:5
@format_concat.lua:5: 1 events +0 bytes -32768 bytes
HEAP SUMMARY:
@format_concat.lua:5 holds 65536 bytes: 10000 allocs, 9999 frees
В: Что изменится, если включить компиляцию JIT?
О: Закомментируйте вторую строку (jit.off()
) в коде и запустите профилировщик. Теперь в отчете только 56 событий. Остальные события связаны с JIT (см. также соответствующую задачу на GitHub):
ALLOCATIONS
@format_concat.lua:5: 56 events +1112 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
INTERNAL: 2 events +382 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 58 events +0 bytes -1164 bytes
Overrides:
@format_concat.lua:5
INTERNAL
HEAP SUMMARY:
@format_concat.lua:0 holds 640 bytes: 4 allocs, 0 frees
INTERNAL holds 360 bytes: 2 allocs, 1 frees
Так произошло потому, что трассировка была скомпилирована после 56 итераций (это значение параметра компилятора hotloop
по умолчанию). Затем JIT-компилятор удалил из трассировки неиспользуемую переменную c
, а вместе с ней и неиспользуемый код функции concat()
.
Теперь включите компиляцию JIT и запустите профилирование только для функции format()
. Для этого закомментируйте строки 2 и 24 (jit.off()
и local c = concat(i)
), раскомментируйте строку 23 (local f = format(i)
) и вызовите профилировщик. Результат будет такой:
ALLOCATIONS
@format_concat.lua:10: 19996 events +624284 bytes -0 bytes
INTERNAL: 4 events +66928 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 19997 events +0 bytes -559034 bytes
Overrides:
@format_concat.lua:0
@format_concat.lua:10
@format_concat.lua:10: 2 events +0 bytes -98304 bytes
Overrides:
@format_concat.lua:10
HEAP SUMMARY:
INTERNAL holds 66928 bytes: 4 allocs, 0 frees
@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees
В: Откуда так много событий аллокации по сравнению с concat()
?
О: Ответ прост: LuaJIT еще не скомпилировал функцию string.format()
с идентификатором %s
. Поэтому трассировка не регистрируется, а компилятор не выполняет соответствующую оптимизацию.
Изменим функцию format
в строках 9–12 примера для анализа отчета о профилировании следующим образом:
local function format(a)
local nstr = string.format("%sa", tostring(a))
return nstr
end
Теперь отчет о профилировании будет выглядеть намного лучше:
ALLOCATIONS
@format_concat.lua:10: 109 events +2112 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
INTERNAL: 3 events +1206 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 112 events +0 bytes -2460 bytes
Overrides:
@format_concat.lua:0
@format_concat.lua:10
INTERNAL
HEAP SUMMARY:
INTERNAL holds 1144 bytes: 3 allocs, 1 frees
@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees
Сводка изменений в динамической памяти и параметр –leak-only
Эта функциональная возможность появилась в версии 2.8.1.
В конце каждого отчета приводится раздел HEAP SUMMARY (сводка изменений в динамической памяти). Этот раздел выглядит так:
@<имя_файла>:<номер_строки> holds <количество_доступных_байтов> bytes: <количество_событий_аллокации> allocs, <количество_событий_деаллокации> frees
Иногда программа может вызывать множество событий деаллокации. В этом случае раздел DEALLOCATION сильно увеличится и отчет будет сложно читать. Чтобы уменьшить количество выводимых данных, запустите парсинг с дополнительным параметром --leak-only
. Например, так:
$ tarantool -e 'require("memprof")(arg)' - --leak-only memprof_new.bin
При использовании параметра --leak-only
выводится только раздел HEAP SUMMARY.
Ниже приведен код на Lua — файл format_concat.lua
. Этот код будет исследован с применением отчетов о профилировании памяти.
1-- Отключение аллокации на новых трассах
2jit.off()
3
4local function concat(a)
5 local nstr = a.."a"
6 return nstr
7end
8
9local function format(a)
10 local nstr = string.format("%sa", a)
11 return nstr
12end
13
14collectgarbage()
15
16local binfile = "/tmp/memprof_"..(arg[0]):match("([^/]*).lua")..".bin"
17
18local st, err = misc.memprof.start(binfile)
19assert(st, err)
20
21-- Нагрузка
22for i = 1, 10000 do
23 local f = format(i)
24 local c = concat(i)
25end
26collectgarbage()
27
28local st, err = misc.memprof.stop()
29assert(st, err)
30
31os.exit()
Запустив этот код в Tarantool и выполнив последующий парсинг бинарного профиля в /tmp/memprof_format_concat.bin, вы получите такой отчет о профилировании:
ALLOCATIONS
@format_concat.lua:10: 19996 events +624284 bytes -0 bytes
INTERNAL: 1 events +65536 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 19996 events +0 bytes -558778 bytes
Overrides:
@format_concat.lua:10
@format_concat.lua:10: 2 events +0 bytes -98304 bytes
Overrides:
@format_concat.lua:10
HEAP SUMMARY:
INTERNAL holds 65536 bytes: 1 allocs, 0 frees
Отчет может вызвать такие вопросы:
- Почему нет событий по функции
concat()
? - Почему количество событий — это не целое число?
- Почему в отчете не 10 тысяч событий, а около 20 тысяч?
Во-первых, LuaJIT не создает новую строку, если уже есть строка с такой же нагрузкой (подробнее на сайте lua-users.org/wiki). Это называется интернированием строк. Иными словами, если строка создана с помощью функции format()
, нет необходимости создавать такую же строку с помощью функции concat()
— LuaJIT будет использовать предыдущую.
По этой же причине количество событий аллокации — это не целое число, как можно было бы ожидать при использовании оператора цикла for i = 1, 10000...
. Некоторые строки Tarantool создает для внутренних нужд и встроенных модулей, поэтому часть строк уже существует.
Но откуда столько событий аллокации? Их почти в 2 раза больше, чем можно было бы ожидать. Это происходит потому, что встроенная функция string.format()
каждый раз создает дополнительную строку для идентификатора %s
. То есть в каждой итерации регистрируются два события аллокации: для tostring(i)
и для string.format("%sa", string_i_value)
. Добавив строку local _ = tostring(i)
между строками 22 и 23, вы увидите разницу в поведении.
Чтобы профилировать только функцию concat()
, закомментируйте строку 23 (local f = format(i)
) и запустите профилировщик. Теперь результат будет такой:
ALLOCATIONS
@format_concat.lua:5: 10000 events +284411 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 10000 events +0 bytes -218905 bytes
Overrides:
@format_concat.lua:5
@format_concat.lua:5: 1 events +0 bytes -32768 bytes
HEAP SUMMARY:
@format_concat.lua:5 holds 65536 bytes: 10000 allocs, 9999 frees
В: Что изменится, если включить компиляцию JIT?
О: Закомментируйте вторую строку (jit.off()
) в коде и запустите профилировщик. Теперь в отчете только 56 событий. Остальные события связаны с JIT (см. также соответствующую задачу на GitHub):
ALLOCATIONS
@format_concat.lua:5: 56 events +1112 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
INTERNAL: 2 events +382 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 58 events +0 bytes -1164 bytes
Overrides:
@format_concat.lua:5
INTERNAL
HEAP SUMMARY:
@format_concat.lua:0 holds 640 bytes: 4 allocs, 0 frees
INTERNAL holds 360 bytes: 2 allocs, 1 frees
Так произошло потому, что трассировка была скомпилирована после 56 итераций (это значение параметра компилятора hotloop
по умолчанию). Затем JIT-компилятор удалил из трассировки неиспользуемую переменную c
, а вместе с ней и неиспользуемый код функции concat()
.
Теперь включите компиляцию JIT и запустите профилирование только для функции format()
. Для этого закомментируйте строки 2 и 24 (jit.off()
и local c = concat(i)
), раскомментируйте строку 23 (local f = format(i)
) и вызовите профилировщик. Результат будет такой:
ALLOCATIONS
@format_concat.lua:10: 19996 events +624284 bytes -0 bytes
INTERNAL: 4 events +66928 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 19997 events +0 bytes -559034 bytes
Overrides:
@format_concat.lua:0
@format_concat.lua:10
@format_concat.lua:10: 2 events +0 bytes -98304 bytes
Overrides:
@format_concat.lua:10
HEAP SUMMARY:
INTERNAL holds 66928 bytes: 4 allocs, 0 frees
@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees
В: Откуда так много событий аллокации по сравнению с concat()
?
О: Ответ прост: LuaJIT еще не скомпилировал функцию string.format()
с идентификатором %s
. Поэтому трассировка не регистрируется, а компилятор не выполняет соответствующую оптимизацию.
Изменим функцию format
в строках 9–12 примера для анализа отчета о профилировании следующим образом:
local function format(a)
local nstr = string.format("%sa", tostring(a))
return nstr
end
Теперь отчет о профилировании будет выглядеть намного лучше:
ALLOCATIONS
@format_concat.lua:10: 109 events +2112 bytes -0 bytes
@format_concat.lua:0: 4 events +640 bytes -0 bytes
INTERNAL: 3 events +1206 bytes -0 bytes
REALLOCATIONS
DEALLOCATIONS
INTERNAL: 112 events +0 bytes -2460 bytes
Overrides:
@format_concat.lua:0
@format_concat.lua:10
INTERNAL
HEAP SUMMARY:
INTERNAL holds 1144 bytes: 3 allocs, 1 frees
@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees
Сводка изменений в динамической памяти и параметр –leak-only
Эта функциональная возможность появилась в версии 2.8.1.
В конце каждого отчета приводится раздел HEAP SUMMARY (сводка изменений в динамической памяти). Этот раздел выглядит так:
@<имя_файла>:<номер_строки> holds <количество_доступных_байтов> bytes: <количество_событий_аллокации> allocs, <количество_событий_деаллокации> frees
Иногда программа может вызывать множество событий деаллокации. В этом случае раздел DEALLOCATION сильно увеличится и отчет будет сложно читать. Чтобы уменьшить количество выводимых данных, запустите парсинг с дополнительным параметром --leak-only
. Например, так:
$ tarantool -e 'require("memprof")(arg)' - --leak-only memprof_new.bin
При использовании параметра --leak-only
выводится только раздел HEAP SUMMARY.
Эта функциональная возможность появилась в версии 2.8.1.
В конце каждого отчета приводится раздел HEAP SUMMARY (сводка изменений в динамической памяти). Этот раздел выглядит так:
@<имя_файла>:<номер_строки> holds <количество_доступных_байтов> bytes: <количество_событий_аллокации> allocs, <количество_событий_деаллокации> frees
Иногда программа может вызывать множество событий деаллокации. В этом случае раздел DEALLOCATION сильно увеличится и отчет будет сложно читать. Чтобы уменьшить количество выводимых данных, запустите парсинг с дополнительным параметром --leak-only
. Например, так:
$ tarantool -e 'require("memprof")(arg)' - --leak-only memprof_new.bin
При использовании параметра --leak-only
выводится только раздел HEAP SUMMARY.