Профилировщик памяти LuaJIT

Начиная с версии 2.7.1 в Tarantool встроен модуль misc.memprof, реализующий профилировщик памяти LuaJIT (далее в этом разделе – профилировщик памяти). Профилировщик памяти формирует отчет о событиях выделения памяти, с помощью которого можно анализировать Lua-код и находить участки, создающие наибольшую нагрузку на сборщик мусора (Garbage Collector, GC) Lua.

Использование профилировщика памяти включает два шага:

1. Сбор данных и формирование бинарного профиля событий выделения, перераспределения и освобождения памяти, связанной с Lua (далее в этом разделе – профиль памяти).
2. Разбор собранного профиля памяти для получения человекочитаемого отчета профилирования.

Чтобы собрать профиль памяти для определенной части Lua-кода, необходимо поместить эту часть между двумя функциями misc.memprof, а именно - misc.memprof.start() и misc.memprof.stop(), а затем выполнить код в Tarantool.

Ниже приведен фрагмент Lua-кода с именем test.lua иллюстрирующий это.

 
-- Предотвращение выделений памяти на трассах.jit.off()local str, err = misc.memprof.start("memprof_new.bin")-- Lua не создает новый фрейм для вызова string.rep, и все выделения-- относятся не к функции append(), а к родительской области видимости.local function append(str, rep)    return string.rep(str, rep)endlocal t = {}for i = 1, 1e4 do    -- table.insert — встроенная функция, и все соответствующие    -- выделения относятся к области видимости основного чанка.    table.insert(t,        append('q', i)    )endlocal str, err = misc.memprof.stop()

Lua-код для запуска профилировщика памяти как в строке 3 в приведенном выше примере test.lua выглядит так:

 
local str, err = misc.memprof.start(FILENAME)

где FILENAME – имя бинарного файла, в который записываются события профилирования.

Если операция завершается неудачей, например, невозможно открыть файл для записи или профилировщик памяти уже запущен, misc.memprof.start() возвращает nil в качестве первого результата, строку с сообщением об ошибке – в качестве второго результата и зависящий от системы код ошибки – в качестве третьего результата.

Если операция завершается успешно, misc.memprof.start() возвращает true.

Lua-код для остановки профилировщика памяти – как в строке 18 в приведенном выше примере test.lua - выглядит так:

 
local str, 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(). Подробнее см. примечание о jit.off() в конце раздела.
• Строки 6-8: Оптимизация хвостового вызова не создает новый фрейм вызова, поэтому все выделения памяти внутри функции, вызванной через байткоды CALLT/CALLMT, относятся к вызывающей функции. См. также комментарии перед этими строками.
• Строки 14-16: Обычно информация о выделениях памяти внутри встроенных функций Lua не очень полезна для разработчиков. Поэтому, если встроенная функция Lua вызывается из Lua-функции, профилировщик памяти относит все выделения памяти к этой Lua-функции. В противном случае событие относится к C-функции. См. также комментарии перед этими строками.

После получения профиля памяти в бинарном формате следующим шагом является его разбор для получения человекочитаемого отчета профилирования. Это можно сделать с помощью Tarantool посредством следующей команды (обратите внимание на дефис - перед именем файла):

 
$ tarantool -e 'require("memprof")(arg)' - memprof_new.bin

где memprof_new.bin – профиль памяти, сформированный ранее командой tarantool test.lua.

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 bytesREALLOCATIONS@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        INTERNALINTERNAL: 3 events          +8448 bytes     -16896 bytes    Overrides:        @test.lua:14DEALLOCATIONSINTERNAL: 1723 events       +0 bytes        -483515 bytes@test.lua:14: 1 events      +0 bytes        -32768 bytesHEAP SUMMARY:@test.lua:14 holds 50248326 bytes: 10010 allocs, 10 frees@test.lua:13 holds 131080 bytes: 14 allocs, 13 freesINTERNAL 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

Рассмотрим структуру отчета. Отчет состоит из четырех разделов:

• ALLOCATIONS
• REALLOCATIONS
• DEALLOCATIONS
• HEAP SUMMARY (описан далее в Сводка кучи и параметр –leak-only)

Каждый раздел содержит записи событий, отсортированные от наиболее частых к наименее частым.

Запись события имеет следующий формат:

 
@<filename>:<line_number>: <number_of_events> events +<allocated> bytes -<freed> bytes

где:

• <filename> - имя файла, содержащего Lua-код.
• <line_number> - номер строки, в которой обнаружено событие.
• <number_of_events> - количество событий для этой строки кода.
• +<allocated> bytes - объем памяти, выделенной во время всех событий в этой строке.
• -<freed> bytes – объем памяти, освобожденной во время всех событий в этой строке.

Метка Overrides показывает, какое выделение памяти было переопределено.

Примеры см. в приведенном выше фрагменте test.lua с пояснениями в комментариях.

Метка INTERNAL указывает, что событие вызвано внутренними структурами LuaJIT.

Что касается исследования Lua-кода с помощью отчетов профилирования, то здесь всё зависит от конкретного кода, и точных рекомендаций на этот счет быть не может. Тем не менее, некоторые моменты рассмотрены далее в примере анализа отчета профилирования.

Ниже также приведен раздел FAQ с вопросами, которые могут возникнуть при использовании профилировщика памяти.

В этом разделе рассматриваются некоторые вопросы, связанные с профилировщиком памяти, в формате вопросов и ответов.

Вопрос (В): Подходит ли профилировщик памяти для отслеживания выделения памяти в C или выделения памяти внутри кода на C?

Ответ (О): Профилировщик памяти сообщает только о событиях выделения памяти, вызванных аллокатором Lua. Отчеты включают все выделения памяти, связанные с Lua, такие как создание таблиц или строк. Однако профилировщик памяти не сообщает о выделениях памяти, сделанных с помощью malloc() или других аллокаторов, не относящихся к Lua. Для их отладки можно использовать valgrind.

В: Почему в моем отчете профилирования так много выделений памяти INTERNAL? Что это значит?

О: INTERNAL означает, что эти выделения/перераспределения/освобождения памяти связаны с внутренними структурами LuaJIT или происходят в трассах. В настоящее время профилировщик памяти не предоставляет подробного отчета о выделении памяти для объектов, которое происходит во время выполнения трассы. Попробуйте добавить jit.off() перед запуском профилировщика памяти.

В: Почему некоторые перераспределения/освобождения памяти происходят без раздела Overrides?

О: Эти объекты могли быть созданы до запуска профилировщика памяти. Добавление collectgarbage() перед запуском профилировщика памяти позволяет собрать все ранее выделенные объекты, которые стали мертвыми к моменту запуска профилировщика памяти.

В: Почему некоторые объекты не собираются во время профилирования? Это утечка памяти?

О: LuaJIT использует инкрементальный сборщик мусора (GC). Цикл сборки мусора может не завершиться к моменту остановки профилировщика памяти. Добавьте collectgarbage() перед остановкой профилировщика памяти, чтобы гарантированно собрать все мертвые объекты.

В: Можно ли профилировать не только текущий чанк, но и всё запущенное приложение? Можно ли запустить профилировщик памяти, когда приложение уже запущено?

О: Да. Вот пример кода, который можно вставить в консоль Tarantool для работающего экземпляра.

 
local fiber = require "fiber"local log = require "log"fiber.create(function()  fiber.name("memprof")  collectgarbage() -- Сбор всех объектов, которые уже мертвы  log.warn("start of profile")  local st, err = misc.memprof.start(FILENAME)  if not st then    log.error("failed to start profiler: %s", err)  end  fiber.sleep(TIME)  collectgarbage()  st, err = misc.memprof.stop()  if not st then    log.error("profiler on stop error: %s", err)  end  log.warn("end of profile")end)

где:

• FILENAME – имя бинарного файла, в который записываются события профилирования.
• TIME – продолжительность профилирования в секундах.

misc.memprof.start() и misc.memprof.stop() можно выполнять напрямую из консоли.

В приведенном ниже примере для исследования с помощью отчетов профилировщика памяти используется следующий Lua-код из файла format_concat.lua:

 
-- Предотвращение выделений памяти на новых трассах.jit.off()local function concat(a)  local nstr = a.."a"  return nstrendlocal function format(a)  local nstr = string.format("%sa", a)  return nstrendcollectgarbage()local binfile = "/tmp/memprof_"..(arg[0]):match("([^/]*).lua")..".bin"local st, err = misc.memprof.start(binfile)assert(st, err)-- Полезная нагрузка.for i = 1, 10000 do  local f = format(i)  local c = concat(i)endcollectgarbage()local st, err = misc.memprof.stop()assert(st, err)os.exit()

Если этот код запустить в Tarantool, а затем разобрать профиль памяти в /tmp/memprof_format_concat.bin, будет получен следующий отчет профилирования:

 
ALLOCATIONS@format_concat.lua:10: 19996 events +624284 bytes   -0 bytesINTERNAL: 1 events                  +65536 bytes    -0 bytesREALLOCATIONSDEALLOCATIONSINTERNAL: 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:10HEAP SUMMARY:INTERNAL holds 65536 bytes: 1 allocs, 0 frees

Отчет может вызвать следующие вопросы:

• Почему в отчете нет выделений памяти, связанных с функцией concat()?
• Почему количество выделений памяти не является круглым числом?
• Почему в отчете около 20 тысяч выделений вместо 10 тысяч?

В первую очередь LuaJIT не создает новую строку, если строка с тем же содержимым уже существует (подробнее см. на lua-users.org/wiki). Это называется интернированием строк. Поэтому, когда строка создается функцией format(), создавать такую же строку функцией concat() не требуется – LuaJIT просто использует уже существующую строку.

По этой же причине количество выделений памяти не является круглым числом, как можно было бы ожидать из цикла for i = 1, 10000...: Tarantool создает ряд строк для внутренних нужд и встроенных модулей, поэтому некоторые строки уже существуют.

Но почему выделений памяти так много? Это почти в два раза больше ожидаемого количества. Причина в том, что встроенная функция 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 bytesREALLOCATIONSDEALLOCATIONSINTERNAL: 10000 events              +0 bytes         -218905 bytes    Overrides:        @format_concat.lua:5@format_concat.lua:5: 1 events      +0 bytes         -32768 bytesHEAP SUMMARY:@format_concat.lua:5 holds 65536 bytes: 10000 allocs, 9999 frees

В: Что изменится, если включить JIT-компиляцию?

О: В коде закомментируйте строку 2 (jit.off()) и запустите профилировщик памяти. Теперь в отчете всего 56 выделений памяти, а все остальные выделения связаны с JIT (см. соответствующую задачу разработки):

 
ALLOCATIONS@format_concat.lua:5: 56 events +1112 bytes -0 bytes@format_concat.lua:0: 4 events  +640 bytes  -0 bytesINTERNAL: 2 events              +382 bytes  -0 bytesREALLOCATIONSDEALLOCATIONSINTERNAL: 58 events             +0 bytes    -1164 bytes    Overrides:        @format_concat.lua:5        INTERNALHEAP SUMMARY:@format_concat.lua:0 holds 640 bytes: 4 allocs, 0 freesINTERNAL holds 360 bytes: 2 allocs, 1 frees

Это происходит потому, что после 56 итераций была скомпилирована трасса (значение по умолчанию для параметра компилятора hotloop). Затем JIT-компилятор удалил неиспользуемую переменную c из трассы, и, как следствие, мертвый код функции concat() был устранен.

Теперь профилируем только функцию format() с включенным JIT. Для этого закомментируйте строки 2 и 24 (jit.off() и local c = concat(i)), не закомментируйте строку 23 (local f = format(i)) и запустите профилировщик памяти. Теперь вывод будет выглядеть так:

 
ALLOCATIONS@format_concat.lua:10: 19996 events +624284 bytes  -0 bytesINTERNAL: 4 events                  +66928 bytes   -0 bytes@format_concat.lua:0: 4 events      +640 bytes     -0 bytesREALLOCATIONSDEALLOCATIONSINTERNAL: 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:10HEAP SUMMARY:INTERNAL holds 66928 bytes: 4 allocs, 0 frees@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees

В: Почему выделений памяти так много по сравнению с функцией concat()?

О: Функция string.format() со спецификатором %s пока не компилируется с помощью LuaJIT. Поэтому записать трассу невозможно, и компилятор не выполняет соответствующие оптимизации.

Если изменить функцию format() в строках 9-12 примера кода format_concat.lua следующим образом:

 
local function format(a)  local nstr = string.format("%sa", tostring(a))  return nstrend

то отчет профилирования станет гораздо нагляднее:

 
ALLOCATIONS@format_concat.lua:10: 109 events   +2112 bytes -0 bytes@format_concat.lua:0: 4 events      +640 bytes  -0 bytesINTERNAL: 3 events                  +1206 bytes -0 bytesREALLOCATIONSDEALLOCATIONSINTERNAL: 112 events                +0 bytes    -2460 bytes    Overrides:        @format_concat.lua:0        @format_concat.lua:10        INTERNALHEAP SUMMARY:INTERNAL holds 1144 bytes: 3 allocs, 1 frees@format_concat.lua:0 holds 384 bytes: 4 allocs, 1 frees

Эта возможность добавлена в версии 2.8.1.

В конце каждого отчета находится раздел HEAP SUMMARY, который выглядит так:

 
@<filename>:<line number> holds <number of still reachable bytes> bytes:<number of allocation events> allocs, <number of deallocation events> frees

Иногда программа может вызывать множество освобождений памяти, из-за чего раздел DEALLOCATION разрастается и отчет становится трудночитаемым. Чтобы сократить вывод, запустите разбор с дополнительным параметром --leak-only, например

 
$ tarantool -e 'require("memprof")(arg)' - --leak-only memprof_new.bin

При использовании --leak-only отображается только раздел HEAP SUMMARY.