ruby on rails - software - Error de subprocesamiento al usar `ActiveRecord with_connection do` & ActionController:: Live

ruby on rails software

Question

Edición principal: desde que originalmente encontré este problema lo he reducido al siguiente. Creo que esta es ahora una descripción marginalmente más precisa del problema. Por lo tanto, los comentarios sobre el OP pueden no correlacionarse por completo.

Edite una versión ligeramente modificada publicada en proyectos rails / puma: https://github.com/rails/rails/issues/21209 , https://github.com/puma/puma/issues/758

Editar ahora reproducido con OS X y Rainbows

Resumen: cuando uso Puma y ejecuto conexiones de larga ejecución, recibo constantemente errores relacionados con las conexiones de ActiveRecord que cruzan hilos. Esto se manifiesta en mensajes como el message type 0x## arrived from server while idle y un servidor bloqueado (bloqueado).

La puesta en marcha:

• 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
• Rieles ( 4.2.3 , 4.2.1 )
• Puma ( 2.12.2 , 2.11 )
• pg ( pg-0.18.2 ) / mysql2

Tenga en cuenta que no se han probado todas las combinaciones de las versiones anteriores. La primera versión enumerada es contra la que estoy probando actualmente.

• rails new issue-test
• Agregue una ruta get ''events'' => ''streaming#events''
• Agregue un controlador streaming_controller.rb
• Configurar cosas de la base de datos ( pool: 2 , pero visto con diferentes tamaños de grupo)

Código:

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

Configuración 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

• Ejecute el servidor puma -e production -C path/to/puma/config/production.rb

Secuencia de comandos de prueba:

#!/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

Esto resulta razonablemente consistente en un bloqueo completo del servidor de aplicaciones (en PostgreSQL, ver notas). El mensaje aterrador proviene de 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

En el "mundo real" tengo bastantes elementos adicionales y el problema se presenta al azar. Mi investigación indica que este mensaje proviene de libpq y es un subtexto para ''problema de comunicación, posiblemente usando conexión en diferentes subprocesos'' . Finalmente, mientras escribía esto, bloqueé el servidor sin un solo mensaje en ningún registro.

Entonces, la pregunta (s):

1. ¿El patrón que estoy siguiendo no es legal de alguna manera? ¿Qué he mal [sed | entendido]?
2. ¿Cuál es el "estándar" para trabajar con conexiones de bases de datos que deberían evitar estos problemas?
3. ¿Puedes ver una manera de reproducir esto de manera confiable?

o

1. ¿Cuál es el problema subyacente aquí y cómo puedo solucionarlo?

MySQL

Si ejecuta MySQL, el mensaje es un poco diferente, y la aplicación se recupera (aunque no estoy seguro si está en algún estado indefinido):

F, [2015-07-30T14:12:07.078215 #15606] FATAL -- :
ActiveRecord::StatementInvalid (Mysql2::Error: This connection is in use by: #<Thread:0x007f563b2faa88@/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):

Answer 1

Advertencia: lea "responder" ya que "parece marcar la diferencia"

No veo el problema si cambio el bloque del controlador para que se vea así:

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

Pero no sé si esto realmente ha resuelto el problema o simplemente lo hizo extremadamente improbable. Tampoco puedo comprender por qué esto marcaría la diferencia.

Publicar esto como una solución en caso de que sea útil, pero aún profundizar en el tema.