Подтвердить что ты не робот

Ошибка Threading при использовании `ActiveRecord with_connection do` & ActionController:: Live

Основное изменение:. С тех пор, как я впервые нашел эту проблему, я уменьшил ее до уровня ниже. Я думаю, что это теперь немного более точное описание проблемы. Поэтому комментарии к ОП не могут полностью коррелировать.

Изменить слегка измененную версию, опубликованную в проектах rails/puma: https://github.com/rails/rails/issues/21209, https://github.com/puma/puma/issues/758

Изменить Теперь воспроизводится с OS X и Rainbows

Резюме: При использовании Puma и длительных подключений я постоянно получаю ошибки, связанные с соединениями ActiveRecord, пересекающими потоки. Это проявляется в сообщении типа message type 0x## arrived from server while idle и заблокированном (разбитом) сервере.

Настройка:

  • Ubuntu 15/OSX Yosemite
  • PostgreSQL (9.4)/MySQL (mysqld 5.6.25-0ubuntu0.15.04.1)
  • Ruby - MRI 2.2.2p95 (2015-04-13 revision 50295) [x86_64-linux]/Rubinius rbx-2.5.8
  • Rails (4.2.3, 4.2.1)
  • Puma (2.12.2, 2.11)
  • pg (pg-0.18.2)/mysql2

Обратите внимание, что не все комбинации вышеуказанных версий были опробованы. Первая указанная версия - это то, что я сейчас тестирую.

  • rails new issue-test
  • Добавить маршрут get 'events' => 'streaming#events'
  • Добавить контроллер streaming_controller.rb
  • Настроить материал базы данных (pool: 2, но видно с разными размерами пула)

код:

class StreamingController < ApplicationController

  include ActionController::Live

  def events
    begin
      response.headers["Content-Type"] = "text/event-stream"
      sse = SSE.new(response.stream)
      sse.write( {:data => 'starting'} , {:event => :version_heartbeat})
      ActiveRecord::Base.connection_pool.release_connection
      while true do
        ActiveRecord::Base.connection_pool.with_connection do |conn|
          ActiveRecord::Base.connection.query_cache.clear
          logger.info 'START'
          conn.execute 'SELECT pg_sleep(3)'
          logger.info 'FINISH'
          sse.write( {:data => 'continuing'}, {:event => :version_heartbeat})
          sleep 0.5
         end
      end
    rescue IOError
    rescue ClientDisconnected
    ensure
      logger.info 'Ensuring event stream is closed'
      sse.close
    end
    render nothing: true
  end
end

Конфигурация Puma:

workers 1
threads 2, 2
#...
bind "tcp://0.0.0.0:9292"

#...
activate_control_app

on_worker_boot do
  require "active_record"
  ActiveRecord::Base.connection.disconnect! rescue ActiveRecord::ConnectionNotEstablished
  ActiveRecord::Base.establish_connection(YAML.load_file("#{app_dir}/config/database.yml")[rails_env])
end
  • Запустите сервер puma -e production -C path/to/puma/config/production.rb

Тест script:

#!/bin/bash

timeout 30 curl -vS http://0.0.0.0/events &
timeout 5 curl -vS http://0.0.0.0/events &
timeout 30 curl -vS http://0.0.0.0/events

Это разумно последовательно приводит к полной блокировке сервера приложений (в PostgreSQL, см. примечания). Страшное сообщение происходит от libpq:

message type 0x44 arrived from server while idle
message type 0x43 arrived from server while idle
message type 0x5a arrived from server while idle
message type 0x54 arrived from server while idle

В "реальном мире" у меня есть немало дополнительных элементов, и проблема возникает наугад. Мои исследования показывают, что это сообщение исходит от libpq и является подтекстом для "проблемы связи, возможно, с использованием соединения в разных потоках". Наконец, при написании этого, я заблокировал сервер без единого сообщения в любом журнале.

Итак, вопрос (ы):

  • Является ли шаблон, который я слежу, не является законным каким-то образом? Что я неправильно понял [?]?
  • Что такое "стандарт" для работы с подключениями к базе данных здесь, чтобы избежать этих проблем?
  • Вы можете увидеть способ достоверно воспроизвести это?

или

  • В чем заключается основная проблема и как я могу ее решить?

MySQL

При запуске MySQL сообщение немного отличается, и приложение восстанавливается (хотя я не уверен, что он находится в каком-то состоянии undefined):

F, [2015-07-30T14:12:07.078215 #15606] FATAL -- : 
ActiveRecord::StatementInvalid (Mysql2::Error: This connection is in use by: #<Thread:[email protected]/home/dev/.rbenv/versions/2.2.2/lib/ruby/gems/2.2.0/gems/actionpack-4.2.3/lib/action_controller/metal/live.rb:269 sleep>: SELECT  `tasks`.* FROM `tasks`  ORDER BY `tasks`.`id` ASC LIMIT 1):
4b9b3361

Ответ 1

Предупреждение: читайте "ответ" как "кажется, имеет значение"


Я не вижу проблемы, если я изменил блок контроллера, чтобы выглядеть так:

begin
  #...
  while true do
    t = Thread.new do #<<<<<<<<<<<<<<<<<
        ActiveRecord::Base.connection_pool.with_connection do |conn|
            #...
        end
     end
     t.join #<<<<<<<<<<<<<<<<<
  end
  #...
rescue IOError
#...

Но я не знаю, действительно ли это решило проблему или просто сделало ее крайне маловероятной. Я также не могу понять, почему это имеет значение.

Проводя это как решение в случае, если оно помогает, но все еще копается в проблеме.