ruby-on-rails - start - phusion passenger rails

cola de solicitud de unicornio

Question

Acabamos de migrar de pasajero a unicornio para alojar algunas aplicaciones de rieles. Todo funciona bien, pero notamos a través de New Relic que la solicitud está en cola entre 100 y 300 ms.

Aquí está el gráfico:

No tengo idea de dónde viene esto de aquí está nuestra confesión de unicornio:

current_path = ''/data/actor/current''
shared_path = ''/data/actor/shared''
shared_bundler_gems_path = "/data/actor/shared/bundled_gems"
working_directory ''/data/actor/current/''

worker_processes 6

listen ''/var/run/engineyard/unicorn_actor.sock'', :backlog => 1024

timeout 60

pid "/var/run/engineyard/unicorn_actor.pid"

logger Logger.new("log/unicorn.log")

stderr_path "log/unicorn.stderr.log"
stdout_path "log/unicorn.stdout.log"

preload_app true

if GC.respond_to?(:copy_on_write_friendly=)
  GC.copy_on_write_friendly = true
end

before_fork do |server, worker|
  if defined?(ActiveRecord::Base)
    ActiveRecord::Base.connection.disconnect!
  end

  old_pid = "#{server.config[:pid]}.oldbin"

  if File.exists?(old_pid) && server.pid != old_pid
    begin
      sig = (worker.nr + 1) >= server.worker_processes ? :TERM : :TTOU
      Process.kill(sig, File.read(old_pid).to_i)
    rescue Errno::ENOENT, Errno::ESRCH
      # someone else did our job for us
    end
  end
  sleep 1
end

if defined?(Bundler.settings)
  before_exec do |server|
    paths = (ENV["PATH"] || "").split(File::PATH_SEPARATOR)
    paths.unshift "#{shared_bundler_gems_path}/bin"
    ENV["PATH"] = paths.uniq.join(File::PATH_SEPARATOR)

    ENV[''GEM_HOME''] = ENV[''GEM_PATH''] = shared_bundler_gems_path
    ENV[''BUNDLE_GEMFILE''] = "#{current_path}/Gemfile"
  end
end

after_fork do |server, worker|
  worker_pid = File.join(File.dirname(server.config[:pid]), "unicorn_worker_actor_#{worker.nr$
  File.open(worker_pid, "w") { |f| f.puts Process.pid }
  if defined?(ActiveRecord::Base)
    ActiveRecord::Base.establish_connection
  end

end

nuestro nginx.conf:

user deploy deploy;
worker_processes 6;

worker_rlimit_nofile 10240;
pid /var/run/nginx.pid;

events {
  worker_connections 8192;
  use epoll;
}

http {

  include /etc/nginx/mime.types;

  default_type application/octet-stream;

  log_format main ''$remote_addr - $remote_user [$time_local] ''
                  ''"$request" $status $body_bytes_sent "$http_referer" ''
                  ''"$http_user_agent" "$http_x_forwarded_for"'';

  sendfile on;

  tcp_nopush        on;

  server_names_hash_bucket_size  128;

  if_modified_since before;
  gzip              on;
  gzip_http_version 1.0;
  gzip_comp_level   2;
  gzip_proxied      any;
  gzip_buffers      16 8k;
  gzip_types        application/json text/plain text/html text/css application/x-javascript t$
  # gzip_disable      "MSIE [1-6]/.(?!.*SV1)";

  # Allow custom settings to be added to the http block
  include /etc/nginx/http-custom.conf;
  include /etc/nginx/stack.conf;
  include /etc/nginx/servers/*.conf;
}

y nuestra aplicación específica nginx conf:

upstream upstream_actor_ssl {
  server unix:/var/run/engineyard/unicorn_actor.sock fail_timeout=0;
}

server {
  listen 443;

  server_name letitcast.com;

  ssl on;
  ssl_certificate /etc/nginx/ssl/letitcast.crt;
  ssl_certificate_key /etc/nginx/ssl/letitcast.key;
  ssl_session_cache shared:SSL:10m;

  client_max_body_size 100M;

  root /data/actor/current/public;

  access_log /var/log/engineyard/nginx/actor.access.log main;
  error_log /var/log/engineyard/nginx/actor.error.log notice;

  location @app_actor {
    include /etc/nginx/common/proxy.conf;
    proxy_pass http://upstream_actor_ssl;
  }

  include /etc/nginx/servers/actor/custom.conf;
  include /etc/nginx/servers/actor/custom.ssl.conf;

  if ($request_filename ~* /.(css|jpg|gif|png)$) {
    break;
  }

  location ~ ^/(images|javascripts|stylesheets)/ {
    expires 10y;
  }

  error_page 404 /404.html;
  error_page 500 502 504 /500.html;
  error_page 503 /system/maintenance.html;

  location = /system/maintenance.html { }

  location / {
    if (-f $document_root/system/maintenance.html) { return 503; }

    try_files  $uri $uri/index.html $uri.html @app_actor;
  }

  include /etc/nginx/servers/actor/custom.locations.conf;
}

No estamos bajo mucha carga, por lo que no entiendo por qué las solicitudes están atrapadas en la cola. Como se especifica en la confesión de unicornio, tenemos 6 trabajadores de unicornio.

¿Alguna idea de dónde podría venir esto?

Aclamaciones

EDITAR:

Promedio de solicitudes por minuto: alrededor de 15 la mayoría de las veces, más de 300 en peeks pero no experimentamos uno desde la migración.
Promedio de carga de CPU: 0.2-0.3

Intenté con 8 trabajadores, no cambió nada.

También usé raindrops de raindrops para ver qué hacían los trabajadores del unicornio.

Aquí está el script de ruby:

#!/usr/bin/ruby

# this is used to show or watch the number of active and queued
# connections on any listener socket from the command line

require ''raindrops''
require ''optparse''
require ''ipaddr''
usage = "Usage: #$0 [-d delay] ADDR..."
ARGV.size > 0 or abort usage
delay = false

# "normal" exits when driven on the command-line
trap(:INT) { exit 130 }
trap(:PIPE) { exit 0 }

opts = OptionParser.new('''', 24, ''  '') do |opts|
  opts.banner = usage
  opts.on(''-d'', ''--delay=delay'') { |nr| delay = nr.to_i }
  opts.parse! ARGV
end

socks = []
ARGV.each do |f|
  if !File.exists?(f)
    puts "#{f} not found"
    next
  end

  if !File.socket?(f)
    puts "#{f} ain''t a socket"
    next
  end

  socks << f
end

fmt = "% -50s % 10u % 10u/n"
printf fmt.tr(''u'',''s''), *%w(address active queued)

begin
  stats = Raindrops::Linux.unix_listener_stats(socks)
  stats.each do |addr,stats| 
    if stats.queued.to_i > 0
      printf fmt, addr, stats.active, stats.queued
    end
  end
end while delay && sleep(delay)

Cómo lo lancé:

./linux-tcp-listener-stats.rb -d 0.1 /var/run/engineyard/unicorn_actor.sock

Por lo tanto, básicamente comprueba cada 1 / 10s si hay solicitudes en la cola y si hay salidas:

el zócalo | la cantidad de solicitudes que se procesan | el número de solicitudes en la cola

Aquí hay una esencia del resultado:

https://gist.github.com/f9c9e5209fbbfc611cb1

EDIT2:

Traté de reducir el número de trabajadores de nginx a uno anoche, pero no cambió nada.

Para obtener información, estamos alojados en Engine Yard y tenemos una instancia media de alta CPU de 1,7 GB de memoria, 5 unidades informáticas EC2 (2 núcleos virtuales con 2,5 unidades informáticas EC2)

Tenemos 4 aplicaciones de rieles, esta tiene 6 trabajadores, tenemos uno con 4, uno con 2 y otro con uno. Todos están experimentando colas de solicitudes desde que migramos al unicornio. No sé si Passenger estaba engañando, pero New Relic no registró ninguna cola de solicitud cuando la estábamos usando. También tenemos una aplicación node.js que maneja cargas de archivos, una base de datos mysql y 2 redis.

EDIT 3:

Estamos usando ruby ​​1.9.2p290, nginx 1.0.10, unicorn 4.2.1 y newrelic_rpm 3.3.3. Intentaré sin newrelic mañana y le dejaré saber los resultados aquí, pero para la información que usamos pasajeros con nueva reliquia, la misma versión de ruby ​​y nginx y no tuve ningún problema.

EDIT 4:

Traté de aumentar el client_body_buffer_size y proxy_buffers con

client_body_buffer_size 256k;
proxy_buffers 8 256k;
Pero no funcionó.

EDIT 5:

Finalmente lo descubrimos ... drumroll ... El ganador fue nuestro cifrado SSL. Cuando lo cambiamos a RC4, vimos que la cola de peticiones caía de 100 a 300 ms a 30 a 100 ms.

Answer 1

¿Está seguro de que está almacenando en búfer las solicitudes de los clientes en nginx y luego almacenando en búfer las respuestas de los unicornios antes de enviarlos de vuelta a los clientes? Desde su configuración parece que lo hace (porque esto es por defecto), pero le sugiero que lo compruebe dos veces.

La configuración para mirar es:

http://wiki.nginx.org/HttpProxyModule#proxy_buffering

Esto es para amortiguar la respuesta de los unicornios. Definitivamente lo necesita porque no quiere mantener ocupados a los unicornios enviando datos a un cliente lento.

Para el almacenamiento en búfer de la solicitud del cliente, creo que debe observar:

http://wiki.nginx.org/HttpCoreModule#client_body_buffer_size

Creo que todo esto no puede explicar una demora de 100 ms, pero no estoy familiarizado con toda la configuración del sistema, por lo que vale la pena echarle un vistazo a esta dirección. Parece que tus colas no son causadas por una contención de CPU, sino por algún tipo de bloqueo de IO.

Answer 2

¿Qué versión de ruby, unicornio, nginx (no debería importar mucho pero vale la pena mencionar) y newrelic_rpm estás usando?

Además, intentaría ejecutar una prueba de perf de línea base sin newrelic. NewRelic analiza la respuesta y hay casos en que esto puede ser lento debido al problema con ''rindex'' en ruby ​​pre-1.9.3. Esto generalmente solo se nota cuando su respuesta es muy grande y no contiene etiquetas de "cuerpo" (por ejemplo, AJAX, JSON, etc.). Vi un ejemplo de esto donde una respuesta AJAX de 1MB tardaba 30 segundos en analizar NewRelic.

Answer 3

Acabo de diagnosticar un nuevo gráfico reliquia similar al que es totalmente culpa de SSL. Intenta apagarlo. Estamos viendo un tiempo de espera de solicitud de 400 ms, que se reduce a 20 ms sin SSL.

Algunos puntos interesantes sobre por qué algunos proveedores de SSL pueden ser lentos: http://blog.cloudflare.com/how-cloudflare-is-making-ssl-fast