Устранение утечек памяти в приложении на Питоне

Недавно мне довелось разобраться и устранить несколько утечек памяти в популярном фреймворке Торнадо. Не беда, если вы никогда его не использовали, потому что описанное будет мало связано с ним. Рассказать я хочу о методах, которые я использовал для поиска и устранения утечек.

Все сказанное будет по большей части справедливо только для самой популярной реализации Питона — CPython. Как известно, в нем есть два механизма освобождения памяти. Первый из них — подсчет ссылок. Каждый раз, когда вы явно или не явно создаете новый объект, его счетчик ссылок равен единице. Если вы присваиваете этот объект новой переменной или передаете в качестве аргумента, его счетчик ссылок увеличивается. При выходе из функции количество ссылок на объекты, которые были в локальных переменных и аргументах, уменьшается. Если для какого-то объекта количество ссылок становится равным нулю, он немедленно уничтожается.

Это схема отлично работает до тех пор, пока не появляются объекты, ссылающиеся друг на друга. Самый простой пример — узлы какого-то дерева, хранящие ссылки на свои дочерние и родительский узлы. Узлы продолжат ссылаться друг на друга, даже когда не останется других внешних ссылок ни на один из них. Самое неприятное, что такие узлы могут ссылаться на какие-то другие данные и не давать их освободить. Чтобы устранить такие циклические ссылки, в Питоне существует второй механизм освобождения памяти — сборщик мусора. Он запускается время от времени, ставя выполнение остального кода на паузу, и анализирует все неосвобожденные объекты.

Формально, циклические ссылки нельзя назвать утечками: сборка мусора рано или поздно уничтожит такие объекты. Беда только в том, что Питон не может сам определить, когда еще рано, а когда уже поздно. В моем случае система просто прибивала процесс с Питоном, если сборка мусора не начиналась вовремя.

Как сказано в документации модуля gc, частота сборки мусора зависит от установленных порогов на количество новых объектов. Во всех доступных мне версиях Питона это количество по умолчанию равно 700. Однако, если запустить довольно простой тест, можно увидеть, что количество объектов, собранных функцией принудительной сборки мусора gc.collect(), легко может превысить это значение.

class Node(object):
    parent = None

    def __init__(self, *children):
        self.children = list(children)
        for node in self.children:
            node.parent = self

    @classmethod
    def tree(cls, depth=1, children=1):
        if depth == 0:
            return []
        return [cls(*cls.tree(depth-1, children))
                for _ in range(children)]

import gc
from time import time

for n in range(1, 21):
    for _ in range(n):
        # Совершенно случайные величины.
        Node.tree(depth=5, children=6)

    start = time()
    print('{1} objects collected for n={0} in {2:3.6} msec'.format(
          n, gc.collect(), (time() - start) * 1000))

При n равном 10 и 20 у меня получилось по 107 тысяч неосвобожденных объектов. Значит пороги в модуле gc мягкие и их достижение не гарантирует немедленной сборки мусора (Андрей Svetlov в комментариях поправляет, что это не так, и подробно объясняет, почему так происходит). Более того, количество объектов ничего не говорит о занимаемой ими памяти. В результате, если в вашем приложении объекты, занимающие много памяти, не уничтожаются с помощью подсчета ссылок, то это может привести к печальным последствиям.

Именно так и произошло в моем приложении. Код, локализующий проблему, выглядел так:

from tornado import web, ioloop, gen
ioloop = ioloop.IOLoop.current()

class IndexHandler(web.RequestHandler):
    megabyte_string = "0123456789abcdef" * 64 * 1024

    @web.asynchronous
    @gen.engine
    def get(self):
        self.write("Hello, world<br>")
        yield gen.Task(self.some_task, self.megabyte_string * 20)
        self.finish()

    def some_task(self, bigdata, callback):
        self.write("some task<br>")
        callback()

application = web.Application([(r'/', IndexHandler)], debug=True)

if __name__ == "__main__":
    print("Start on 8888")
    application.listen(8888)
    ioloop.start()

Здесь создается сервер, обрабатывающий урл "/" в методе IndexHandler.get(). Метод асинхронный и ставит на выполнение задачу, которой передает большой кусок данных — 20 мегабайт. Что делает задача, не так важно, потому что уже на этом примере наблюдается проблема: с каждым запросом количество памяти, занимаемое процессом Питона, увеличивается на эти 20 мегабайт, и далеко не с каждым уменьшается. В результате простой бенчмарк ab -n 100 -c 4 localhost:8888/ способен в отдельные моменты выедать гигабайты памяти. Но стоит поменять вызов задачи с использования yield gen.Task() на прямой вызов с передачей колбэка, как сервер с легкостью начинает выдерживать нагрузку ab -n 1000 -c 100 localhost:8888/, потребляя не более 50 мб памяти.

    @web.asynchronous
    @gen.engine
    def get(self):
        self.write("Hello, world<br>")
        self.some_task(self.megabyte_string * 20, self.finish)

Как же отлаживать такие случаи? Неплохо было бы посмотреть, что именно не освобождается. Первое, что нужно для этого сделать — обеспечить возможность запускать сборку мусора вручную, чтобы убедиться, что её вызов действительно освобождает память. Я сделал еще один реквест хэндлер, который вызывал gc.collect() и выводил количество собранных объектов.

class HealthHandler(web.RequestHandler):
    def get(self):
        self.write('{} objects collected'.format(gc.collect()))

application = web.Application([(r'/', IndexHandler),
                               (r'/health/', HealthHandler)], debug=True)

Второе — нужно отключить автоматическую сборку мусора. Это позволит получить стабильный результат во время экспериментов. Третье — нужна информация о собранных объектах. В модуле gc уже есть готовое средство для этого — информация будет выводиться в консоль во время вызова gc.collect().

import gc
gc.disable()
gc.set_debug(gc.DEBUG_LEAK)

Теперь получить объекты, причастные именно к этой утечке, довольно просто: нужно запустить метод, который течет, и получить список собранных объектов по адресу /health/. Потом запустить метод, который не течет, получить список для него. Найти объекты из первого списка, которых нет во втором. Вот они:

gc: collectable <cell> × 4
gc: collectable <dict> × 3
gc: collectable <function> × 2
gc: collectable <generator>
gc: collectable <instancemethod>
gc: collectable <Runner>
gc: collectable <set>
gc: collectable <Task>
gc: collectable <tuple> × 3

Для наглядности я сгруппировал одинаковые элементы. В первую очередь интерес представляют невстроенные типы. Здесь это Task и Runner. Это еще раз доказывает, что проблема в вызове yield gen.Task(), и проблема именно в сборке мусора. Осталось разобраться, что это за Runner и почему они с Task ссылаются друг на друга. Открываем исходный код.

Тут нужно отметить, что все примеры будут для версии Торнадо 3.1dev2 на момент моих исследований. В декораторе @gen.engine довольно много кода, но главное, что там происходит — вызывается исходная функция, и, если результат её выполнения оказывается генератором, он передается классу Runner (попался). Наш Task — это то, что вернет генератор. Следовательно, нужно искать место в классе Runner, где генератор итерируется. Это строчка yielded = self.gen.send(next). Ну а дальше довольно легко проследить, что yielded попадает в self.yield_point. Да к тому же у self.yield_point вызывается метод .start(), который сохраняет ссылку на Runner. Получается, после выполнения метода Runner.run() нужно разорвать ссылку либо с одной стороны, либо с другой. Т.к. Runner.yield_point — это всего лишь указатель на последний элемент, а Task.runner — ссылка на родителя, логично обнулить именно указатель на элемент. Осталось только понять, где метод Runner.run() завершает свое выполнение. Т.к. Торнадо асинхронный, а мы ходим по исходникам в самом его сердце, то понять, где тут верх, а где низ, довольно сложно. У метода .run() 5 точек выхода, и он повторно вызывается из всевозможных колбэков. После нескольких попыток я понял, что флаг self.finished у объекта Runner неспроста, и там, где он ставится в True, и нужно обнулять self.yield_point.

Проверяем результат с помощью ab -n 1000 -c 100 localhost:8888/. Все в порядке.

Можно было бы на этом закончить, но вот, что мне показалось странным. Почему вообще любой запрос оставляет в памяти неосвобожденные объекты? Может быть с этим можно что-то сделать. Выяснилось, что все же не любой запрос, а только те, на которых стоит декоратор @web.asynchronous. И список неосвобожденных объектов выглядел так:

gc: collectable <dict> × 7
gc: collectable <list> × 16
gc: collectable <tuple>
gc: collectable <instancemethod>
gc: collectable <ChunkedTransferEncoding>
gc: collectable <ExceptionStackContext>
gc: collectable <HTTPHeaders> × 2
gc: collectable <HTTPRequest>
gc: collectable <IndexHandler>

Тут уже 5 невстроенных объектов, и непонятно, с какого конца начинать. Но я начал с того, что перекрыл метод IndexHandler.finish(), в котором убрал ссылки на все объекты, которые нашел.

class IndexHandler(web.RequestHandler):
    @web.asynchronous
    def get(self):
        self.write("Hello, world<br>")
        self.finish()

    def finish(self, chunk=None):
        super(IndexHandler, self).finish(chunk)

        for k, v in self.__dict__.iteritems():
            print '"{}":'.format(k), type(v)
        self.request = None
        self._headers = None
        self.application = None
        self._transforms = None

Это дало определенный результат, но не решило проблему окончательно. Количество невстроенных неосвобожденных объектов уменьшилось до двух: ExceptionStackContext и сам IndexHandler. ExceptionStackContext создается во время работы декоратора @web.asynchronous с аргументом self._stack_context_handle_exception, где self как раз IndexHandler. Ссылки же в обратную сторону нет. Похоже, ExceptionStackContext ссылается сам на себя. Смотрим реализацию и видим, что действительно, в методе .__enter__() есть строка self.new_contexts = (self.old_contexts[0], self). Значит нужно обнулять self.new_contexts в .__exit__(), и дело в шляпе.

В итоге пулреквест с обоими изменениями был рассмотрен и принят в мастер в течении 2,5 часов, что мотивирует и впредь делать полезные изменения. Торнадо с этими двумя патчами и еще одним совсем перестал оставлять мусор в памяти после запроса. Это уменьшило потребление памяти при многочисленных конкурентных запросах, чуть-чуть ускорило его за счет более быстрой сборки мусора и, самое главное, сделало потребление памяти предсказуемым.

Находить и устранять такие утечки довольно сложно, особенно, если они в коде не самого приложения, а используемых библиотек. Тем не менее, стоит как минимум выяснить, есть ли они у вас в приложении, и убедиться, что никакие тяжелые объекты не висят у вас в памяти из-за них.