Стреляем себе в ногу с помощью GenServer'а, или как мы фиксили неуловимый баг в Elixir проекте

Привет, Хабр! Меня зовут Иван, я — техлид в Каруне.

В команде мы активно используем Elixir в одном из самых нагруженных проектов.

Мы уделяем особое внимание тому, что за код выполняется в коллбеках GenServer'а, особенно если это код третьесторонних библиотек.

В этой статье я расскажу, почему это настолько важно, и продемонстрирую, как с помощью простейших механизмов, которые предоставляют нам Elixir и Erlang, мы можем сломать поведение GenServer'a и породить трудноуловимые баги. Ещё расскажу, как мы боролись с таким багом в реальной жизни.

Поехали!

Key-value хранилище

Начнём с небольшого синтетического примера. Абстракция GenServer'а является одной из основных концепций в Erlang/OTP и Elixir. Принцип работы GenServer'а довольно прост.

Это процесс, который хранит определённое состояние и последовательно обрабатывает входящие сообщения, изменяя это состояние и, возможно, посылая ответные сообщения.

Перед тем, как перейти к тонкостям работы GenServer'а, давайте напишем один из них.

В качестве примера рассмотрим простенькое key-value хранилище, которое может хранить и отдавать значения по ключу.

Ничего сложного: пример, на котором демонстрируют работу GenServer'а во множестве статей и туториалов.

defmodule SimpleKeyValue do
  use GenServer

  def start do
    GenServer.start(__MODULE__, %{})
  end

  def put(pid, key, value) do
    GenServer.cast(pid, {:put, key, value})
  end

  def get(pid, key) do
    GenServer.call(pid, {:get, key})
  end

  # Callbacks
  @impl true
  def init(state) do
    {:ok, state}
  end

  @impl true
  def handle_cast({:put, key, value}, state) do
    {:noreply, Map.put(state, key, value)}
  end

  @impl true
  def handle_call({:get, key}, _from, state) do
    {:reply, Map.fetch!(state, key), state}
  end
end

Запустим этот код в консоли. Как видим, всё работает, как задумано. Мы сохранили значение и смогли впоследствии получить его по ключу

Ломаем GenServer

Пришло время узнать некоторые детали внутренней кухни GenServer'a.

Я считаю, что один из лучших способов понять, как что-то работает — попробовать это что-то сломать.

А для этого давайте посмотрим, что случится с нашим GenServer'ом, если в коллбэке мы запустим свой собственный receive loop:

def run_receive_loop(server) do
  GenServer.cast(server, :run_receive_loop)
end

@impl true
def handle_cast(:run_receive_loop, state) do
  receive do
    msg -> IO.inspect(msg, label: "RECEIVE LOOP")
  end

  {:noreply, state}
end

При запуске обновлённой версии мы получаем такое сообщение об ошибке:

Внимательный читатель уже догадался, что же тут происходит. Как мы знаем, в Elixir'e процессы общаются друг с другом с помощью посылки сообщений (message passing). Вызовы GenServer.call и GenServer.cast внутри себя используют кортежи с ключами :"$gen_call", :"$gen_cast" в качестве сообщений от клиентского процесса процессу GenServer'а. Затем, при помощи pattern matching, receive loop процесса GenServer'а вызывает соответсвующий коллбек. Опустим не важные нам сейчас детали. Выглядит это следующим образом:

def loop(state) do
  receive msg do
    {:"$gen_call", {from, ref}, msg} ->
      callback_result = handle_call(msg, from, state)
      # handle callback result, maybe reply to the client process, call loop again

    {:"$gen_cast", {from, ref}, msg} ->
      callback_result = handle_call(msg, from, state)
      # handle callback result, call loop again
  end
end

Однако в нашем примере handle_cast(:run_receive_loop, state) коллбек запускает вложенный receive loop и перехватывает следующее :"$gen_call" сообщение, адресованное на самом деле внешнему receive loop'у самого GenServer'а. В итоге handle_call коллбэк не отрабатывает, и клиентский процесс крашится по таймаут (по умолчанию 5000 ms), так и не дождавшись ответа на свой запрос SimpleKeyValue.get(pid, :foo).

Пример из жизни

Мы наглядно показали, что запускать вложенный receive loop — не самая хорошая идея, которая может приводить к неопределённому поведению системы и трудноуловимым багам. С одним из них мне как-то и пришлось бороться.

Конечно же, никто не запускал receive loop в коллбеке в явном виде. В реальности всё обычно скрыто за несколькими слоями абстракций.

На одном легаси проекте в качестве HTTP клиента использовалась tesla поверх mint. Периодически в error логах проскакивали сообщения вида Encounter unknown error, иногда после них система крашилась. В общем, баг был плавающий и довольно неприятный.

Грепнув код, я нашёл источник сообщений об ошибке в коде тесловского адаптера к mint'у:

defp stream_response(conn, opts, response \\ %{}) do
  receive do
    msg ->
      case HTTP.stream(conn, msg) do
        {:ok, conn, stream} -> ...

        {:error, _conn, error, _res} -> ...

        :unknown ->
          {:error, "Encounter unknown error"}
      end
  after
    opts |> Keyword.get(:adapter) |> Keyword.get(:timeout) ->
      {:error, "Response timeout"}
  end
end

У меня закралось подозрение, что этот receive loop мог перехватывать "чужие" сообщения, и не распарсив их как валидные HTTP ответы, сваливаться в :unknown clause. Потратив ещё какое-то время на поиск, я обнаружил, что в коллбеке одного GenServer'а выполнялся HTTP запрос. В итоге через цепочку вызовов выше указанный receive loop из stream_response/3 запускался напрямую в коллбеке и иногда перехватывал сообщения, адресованные непосредственно GenServer'у — до того, как получал ожидаемое сообщение от сокета. В общем, всё как я описывал в нашем синтетическом примере.

В итоге HTTP запрос мы обернули в Task, чтобы receive loop выполнялся в контексте отдельного процесса, и проблема разрешилась:

def handle_call(msg, from, state) do
  task = Task.async(fn -> HTTPClient.get_something() end)

  case Task.await(task) do
    {:ok, data} ->
      # handle data

    {:error, reason} ->
      # handle error case (logging, etc)
  end
  
  # ...
end

Заключение

Понимание того, как работает receive loop, а также того, что за интерфейсами GenServer.call и GenServer.castскрывается обычная посылка сообщений процессу GenServer'а помогли нам отловить серьёзный баг и впоследствии проектировать системы более надежным способом.

Я надеюсь, что эта история показалась вам интересной и поучительной. А также приоткрыла некоторую внутреннюю кухню Elixir'а и Erlang'а.

Всем добра и спасибо за внимание!