gazay/short_story.md

## short_story.md

      
    Raw
  

              short_story.md
            
          
    Начиная с версии 2.2.0 (даже с ее превью), руби (mri) может быть причной падения вашего сервера по ООМ.
Моя длительная, многомесячная эпопея с поиском загадочного бага,
которую в подробностях я опишу в следующей статье, окончилась написанием патча в руби.
Сейчас я хотел бы объяснить суть этого бага и суть патча.
Я бы ничего не нашел без помощи моих друзей - Равиля Байрамгалина, который прошел со мной весь путь,
начиная с анализа первых графиков падений и погружения меня во все потаенные тонкости дебага руби приложений,
и Владимира Меньшакова, который в C творит чо хочет вообще и помогал мне с дебагом,
относящимся к C стороне выполнения руби приложений.
Итак, интерпретатор руби (mri) написан на C, многие методы стандартной библиотеки руби реализованы именно на C.
В реализации MRI руби код выполняется на виртуальной машине YARV.
Поэтому при выполнении рубинной программы существует два стека - рубинный и C.
C стек в главном потоке вашей программы ограничен стандартной величиной стека процесса в *nix системах (sysctl kern.stack_depth_max),
то есть 8МБ по умолчанию. В то же время, рубинный стек ограничен значением по умолчанию из vm_core.h размером в 1МБ.
Вы можете изменить его, задав переменную окружения export RUBY_THREAD_VM_STACK_SIZE=10000000 -
этой командой я выставил ограничение рубинного стека всех руби программ в 10МБ.
Все мы знаем, что на руби легко написать рекурсивный метод или создать объект,
ссылающийся на самого себя. Например, это можно сделать так:
def recursion
  recursion
end

recursion # => StackOverflowException

# example 2

class Foo
  def to_s
    puts self
  end
end

Foo.new.to_s # => StackOverflowException
В обоих случаях при вызове метода возникает бесконечная рекурсия,
и в какой-то момент интерпретатор руби выкидывает ошибку о переполнении стека.
Вот только какой стек переполнился? В первом случае все понятно - переполняется только рубинный стек,
так как рекурсивно вызывается руби функция. Во втором все хитрей.
Стандартный метод Kernel#puts вызывает метод $stdout.puts, то есть метод IO#puts. Он написан на C, выглядит вот так:
VALUE
rb_io_puts(int argc, const VALUE *argv, VALUE out)
{
    int i;
    VALUE line;
    // ...
    for (i=0; i<argc; i++) {
        //...
        line = rb_obj_as_string(argv[i]);
        //...
    //...
и нас интересует та его часть, которая срабатывает в нашем случае,
а именно, rb_obj_as_string(argv[i]).
Данный метод определен в string.c и основное, что он делает - вызывает на не строковом объекте рубинный метод to_s.
Таким образом у нас возникает рекурсия, которая содержит в себе не только рубинные методы и объекты, но и C.
Вы скажете, что так как C стек у нас в 8 раз по-умолчанию больше, чем рубинный - переполняется опять рубинный.
Так?
Почти. Смотря где.
Если мы выполняем этот код в главном потоке - то все верно,
у главного потока рубинного процесса ограничения, как я сказал выше.
Но если мы выполняем этот код в новом потоке относительно главного,
там дела обстоят по-другому. Если мы заглянем в тот же самый vm_core.h, а потом в vm.c и thread_pthread.c,
то увидим, какие ограничения выставляются при создании нового потока: 1МБ для C стека.
То есть такой же лимит, как у стека рубинного.
В итоге, если мы выполним код номер 2 (с рекурсивным puts/to_s) внутри Thread.new {},
там мы получим ошибку переполнения стека именно C.
Вы можете проверить, что переполнился нативный стек,
пересобрав руби с парой printf-ов в местах обработки ошибок переполнения стека –
проверка переполнения рубинного стека происходит в vm_insnhelper.c:36,
а C стека в signal.c (поищите там функцию check_stack_overflow – она в разных версиях находится в разных местах).
Итак, становится интереснее - а при чем тут signal.c?
При том, что в зависимости от того мак это или линукс,
при переполнении нативного стека процесса программа получает или сигнал BUS, или сигнал SEGV (ошибка сегментации).
И казалось бы, что в этом такого, ну обрабатывает руби сегфолт внутри потока и ладно –
но все дело в том, как он это делает.
Если мы посмотрим в код обработки сигналов, мы увидим, что происходит выключение GC,
дальше смотрим была ли это ошибка переполнения стека -
если да, то выкидываем обычную рубинную ошибку о переполнении стека.
Ну то есть это не страшная ошибка, и весь процесс выключать из-за нее не надо.
Но вот где проблема - мы выключили GC. Притом так, что обратно нигде его уже не включить.
Раньше в обработке сигнала выключался не весь gc, а режим stress, выставляя rb_disable_gc_stress в 1 (true).
В коммите https://github.com/ruby/ruby/commit/0c391a55d3ed4637e17462d9b9b8aa21e64e2340 это поведение было изменено,
была убрана переменная ruby_disable_gc_stress и логика была изменена так,
что при выставлении новой внутренней переменной ruby_disable_gc в true, проверка на готовность кучи к GC
всегда возвращала бы false. И так как эта переменная могла быть выставлена только в 1 (true) в обработке сигнала и
нигде больше ее не меняют – обработка сигнала означает полное выключение GC.
Чем же это чревато – ну вообще довольно очевидно.
Процесс ваш не упал и работает, как и должен был. Да, произошла ошибка в потоке,
но может быть, что вы ее даже ожидали и сделали rescue.
При этом никакие объекты никогда больше не освободят памяти в процессе,
пока процесс не займет всю доступную память на сервере.
В реальном приложении это была ошибка вызваная нормальной работой двух гемов - Rollbar и OAuth2,
но это мог быть и любой другой гем. Роллбар был включен в режим асинхронной отправки ошибок,
то есть для отправки ошибки создавался новый поток, в котором выполнялся дамп ошибки в json.
А OAuth2 в ошибке сохраняет ссылку на саму себя (oauth-xx/oauth2#201).
В итоге из-за специфической работы rails с json (дамп всех инстанс переменных в json) возникает бесконечная рекурсия,
включающая в себя методы JSON, которые написаны на C и соответствено в новом потоке вызывают переполнение C стека.
В итоге после ЕДИНСТВЕННОЙ такой ошибки у вас выключается GC и это только вопрос времени, когда ваш сервер упадет.
В моем патче лишь одна строчка. В момент, когда интерпретатор понял, что произошла ошибка переполнения стека,
происходит очистка полученного сигнала.
Почти в тот же момент я предлагаю включать обратно GC: https://bugs.ruby-lang.org/issues/11692.
Патч уже принят, скорее всего войдет в руби 2.3. Насчет новой версии 2.2 я не уверен - бэкпорта пока не видел.