Encontrar la causa de una pérdida de memoria en Ruby


He descubierto una fuga de memoria en mi código Rails, es decir, he encontrado lo que el código se filtra, pero no por qué se filtra. Lo he reducido a un testcase que no requiere Rails:

require 'csspool'
require 'ruby-mass'

def report
    puts 'Memory ' + `ps ax -o pid,rss | grep -E "^[[:space:]]*#{$$}"`.strip.split.map(&:to_i)[1].to_s + 'KB'
    Mass.print
end

report

# note I do not store the return value here
CSSPool::CSS::Document.parse(File.new('/home/jason/big.css'))

ObjectSpace.garbage_collect
sleep 1

report

Ruby-mass supuestamente me permite ver todos los objetos en la memoria. CSSPool es un analizador CSS basado en racc. / home / jason / big.css es un archivo CSS de 1,5 MB.

Esto produce:

Memory 9264KB

==================================================
 Objects within [] namespace
==================================================
  String: 7261
  RubyVM::InstructionSequence: 1151
  Array: 562
  Class: 313
  Regexp: 181
  Proc: 111
  Encoding: 99
  Gem::StubSpecification: 66
  Gem::StubSpecification::StubLine: 60
  Gem::Version: 60
  Module: 31
  Hash: 29
  Gem::Requirement: 25
  RubyVM::Env: 11
  Gem::Specification: 8
  Float: 7
  Gem::Dependency: 7
  Range: 4
  Bignum: 3
  IO: 3
  Mutex: 3
  Time: 3
  Object: 2
  ARGF.class: 1
  Binding: 1
  Complex: 1
  Data: 1
  Gem::PathSupport: 1
  IOError: 1
  MatchData: 1
  Monitor: 1
  NoMemoryError: 1
  Process::Status: 1
  Random: 1
  RubyVM: 1
  SystemStackError: 1
  Thread: 1
  ThreadGroup: 1
  fatal: 1
==================================================

Memory 258860KB

==================================================
 Objects within [] namespace
==================================================
  String: 7456
  RubyVM::InstructionSequence: 1151
  Array: 564
  Class: 313
  Regexp: 181
  Proc: 113
  Encoding: 99
  Gem::StubSpecification: 66
  Gem::StubSpecification::StubLine: 60
  Gem::Version: 60
  Module: 31
  Hash: 30
  Gem::Requirement: 25
  RubyVM::Env: 13
  Gem::Specification: 8
  Float: 7
  Gem::Dependency: 7
  Range: 4
  Bignum: 3
  IO: 3
  Mutex: 3
  Time: 3
  Object: 2
  ARGF.class: 1
  Binding: 1
  Complex: 1
  Data: 1
  Gem::PathSupport: 1
  IOError: 1
  MatchData: 1
  Monitor: 1
  NoMemoryError: 1
  Process::Status: 1
  Random: 1
  RubyVM: 1
  SystemStackError: 1
  Thread: 1
  ThreadGroup: 1
  fatal: 1
==================================================

Puedes ver que la memoria va way up. Algunos de los contadores suben, pero no hay objetos específicos de CSSPool presentes. Usé el método "index" de ruby-mass para inspeccionar los objetos que tienen referencias como estas:

Mass.index.each do |k,v|
    v.each do |id|
        refs = Mass.references(Mass[id])
        puts refs if !refs.empty?
    end
end

Pero de nuevo, esto no me da nada relacionado con CSSPool, solo información de gemas y cosas así.

También he intentado generar " GC.stat"...

puts GC.stat
CSSPool::CSS::Document.parse(File.new('/home/jason/big.css'))
ObjectSpace.garbage_collect
sleep 1
puts GC.stat

Resultado:

{:count=>4, :heap_used=>126, :heap_length=>138, :heap_increment=>12, :heap_live_num=>50924, :heap_free_num=>24595, :heap_final_num=>0, :total_allocated_object=>86030, :total_freed_object=>35106}
{:count=>16, :heap_used=>6039, :heap_length=>12933, :heap_increment=>3841, :heap_live_num=>13369, :heap_free_num=>2443302, :heap_final_num=>0, :total_allocated_object=>3771675, :total_freed_object=>3758306}

Según lo entiendo, si no se hace referencia a un objeto y ocurre la recolección de basura, entonces ese objeto debe ser borrada de la memoria. Pero eso no parece ser lo que está pasando aquí.

También he leído acerca de las fugas de memoria de nivel C, y dado que CSSPool utiliza Racc que utiliza código C, creo que esto es una posibilidad. He ejecutado mi código a través de Valgrind:

valgrind --partial-loads-ok=yes --undef-value-errors=no --leak-check=full --fullpath-after= ruby leak.rb 2> valgrind.txt

Los resultados son aquí . No estoy seguro de si esto confirma una fuga de nivel C, ya que también he leído que Ruby hace cosas con memoria que Valgrind no entiende.

Versiones utilizadas:

  • Ruby 2.0.0-p247 (esto es lo que mi aplicación Rails se ejecuta)
  • Ruby 1.9.3-p392-ref (para pruebas con ruby-mass)
  • ruby-mass 0.1.3{[46]]}
  • CSSPool 4.0.0 de aquí
  • CentOS 6.4 y Ubuntu 13.10
Author: np_, 2013-12-05

4 answers

Parece que estás entrando , El Mundo Perdido aquí. No creo que el problema sea con los enlaces c en racc tampoco.

La gestión de la memoria Ruby es elegante y engorrosa. Almacena objetos (llamados RVALUE s) en los llamados montones de tamaño de aproximadamente 16KB. En un nivel bajo, RVALUE es una estructura c, que contiene un union de diferentes representaciones estándar de objetos ruby.

Por lo tanto, los montones almacenan objetos RVALUE, cuyo tamaño no es más de 40 bytes. Para objetos tales como String, Array, Hash etc. esto significa que los objetos pequeños pueden caber en el montón, pero tan pronto como alcancen un umbral, se asignará una memoria extra fuera de los montones de Ruby.

Esta memoria extra es flexible; se liberará tan pronto como un objeto se convierta en GC'ed. Es por eso que su testcase con big_string muestra el comportamiento de subida-bajada de la memoria:

def report
  puts 'Memory ' + `ps ax -o pid,rss | grep -E "^[[:space:]]*#{$$}"`
          .strip.split.map(&:to_i)[1].to_s + 'KB'
end
report
big_var = " " * 10000000
report
big_var = nil 
report
ObjectSpace.garbage_collect
sleep 1
report
# ⇒ Memory 11788KB
# ⇒ Memory 65188KB
# ⇒ Memory 65188KB
# ⇒ Memory 11788KB

Pero los montones (ver GC[:heap_length]) en sí mismos no se liberan de vuelta al sistema operativo, una vez adquiridos. Mira, voy a hacer una monotonía cambiar a su testcase:

- big_var = " " * 10000000
+ big_var = 1_000_000.times.map(&:to_s)

Y, voilá:

# ⇒ Memory 11788KB
# ⇒ Memory 65188KB
# ⇒ Memory 65188KB
# ⇒ Memory 57448KB

La memoria ya no se devuelve al sistema operativo, porque cada elemento del array que introduje corresponde a el tamaño RVALUE y se almacena en el montón de ruby.

Si examina la salida de GC.stat después de ejecutar el GC, encontrará que el valor de GC[:heap_used] se reduce como se esperaba. Ruby ahora tiene un montón de montones vacíos, listos.

El resumen: No creo, el código c fuga. Creo que el problema está dentro de la representación base64 de la imagen enorme en su css. No tengo ni idea, lo que está sucediendo dentro de parser, pero parece que la cadena enorme obliga a la cuenta de montón de ruby para aumentar.

Espero que ayude.

 34
Author: mudasobwa,
Warning: date(): Invalid date.timezone value 'Europe/Kyiv', we selected the timezone 'UTC' for now. in /var/www/agent_stack/data/www/ajaxhispano.com/template/agent.layouts/content.php on line 61
2013-12-16 10:24:01

Bien, encontré la respuesta. Dejo mi otra respuesta porque esa información fue muy difícil de reunir, está relacionada y podría ayudar a alguien más a buscar un tema relacionado.

Su problema, sin embargo, parece deberse al hecho de que Ruby en realidad hace no liberar memoria de nuevo al Sistema Operativo una vez que la ha adquirido.

Asignación de memoria

Mientras que los programadores de Ruby no suelen preocuparse por la asignación de memoria, a veces surge la siguiente pregunta:

¿Por qué mi proceso Ruby sigue siendo tan grande incluso después de haber borrado todas las referencias a objetos grandes? Estoy/ seguro / GC ha corrido varias veces y liberó mis objetos grandes y no estoy perdiendo memoria.

Un programador C podría hacer la misma pregunta:

I free()-ed a lot of memory, why is my process still so big?

La asignación de memoria al espacio de usuario desde el núcleo es más barata en trozos grandes, por lo que el espacio de usuario evita la interacción con kernel haciendo más trabajo por sí mismo.

Las bibliotecas de espacio de usuario/runtimes implementan un asignador de memoria (por ejemplo: malloc(3) en libc) que toma grandes trozos de memoria del kernel2 y los divide en trozos más pequeños para que los usen las aplicaciones de espacio de usuario.

Por lo tanto, varias asignaciones de memoria de espacio de usuario pueden ocurrir antes de que el espacio de usuario necesite pedir más memoria al núcleo. Por lo tanto, si tienes una gran parte de la memoria del núcleo y solo están utilizando una pequeña parte de eso, esa gran parte de la memoria permanece asignada.

Devolver la memoria al núcleo también tiene un costo. Los asignadores de memoria de espacio de usuario pueden retener esa memoria (en privado) con la esperanza de que pueda ser reutilizada dentro del mismo proceso y no devolverla al núcleo para su uso en otros procesos. (Prácticas óptimas de Ruby)

Por lo tanto, es muy posible que sus objetos hayan sido recolectados y liberados de nuevo a la memoria disponible de Ruby, pero debido a que Ruby nunca devuelve la memoria no utilizada al sistema operativo, el el valor rss para el proceso sigue siendo el mismo, incluso después de la recolección de basura. Esto es en realidad por diseño. Según Mike Perham :

...Y dado que la resonancia magnética nunca devuelve la memoria no utilizada, nuestro demonio puede tomar fácilmente 300-400MB cuando solo usa 100-200.

Es importante tener en cuenta que esto es esencialmente por diseño. El historial de Ruby es principalmente como una herramienta de línea de comandos para el procesamiento de texto y, por lo tanto, valora el inicio rápido y una pequeña huella de memoria. Fue no está diseñado para procesos de servidor/demonio de larga duración. Java hace una compensación similar en sus máquinas virtuales cliente y servidor.

 13
Author: Joe Edgar,
Warning: date(): Invalid date.timezone value 'Europe/Kyiv', we selected the timezone 'UTC' for now. in /var/www/agent_stack/data/www/ajaxhispano.com/template/agent.layouts/content.php on line 61
2013-12-05 05:56:53

Esto podría ser debido a la característica de "Barrido lento" en Ruby 1.9.3 y superiores.

El barrido perezoso básicamente significa que, durante la recolección de basura, Ruby solo "barre" suficientes objetos para crear espacio para los nuevos objetos que necesita crear. Lo hace porque, mientras el recolector de basura Ruby se ejecuta, nada más lo hace. Esto se conoce como "Detener el mundo" recolección de basura.

Esencialmente, el barrido perezoso reduce el tiempo que Ruby necesita para "detener el mundo."Usted puede leer más acerca de lazy sweeping aquí .

¿Cómo se ve su variable de entorno RUBY_GC_MALLOC_LIMIT?

Aquí hay un extracto de El blog de Sam Saffron sobre el barrido perezoso y el RUBY_GC_MALLOC_LIMIT:

El GC en Ruby 2.0 viene en 2 sabores diferentes. Tenemos un GC "completo" que se ejecuta después de asignar más que nuestro malloc_limit y un barrido perezoso (GC parcial) que se ejecutará si alguna vez nos quedamos sin ranuras libres en nuestros montones.

El barrido perezoso toma menos tiempo que un GC completo, sin embargo solo realiza un GC parcial. Su objetivo es realizar un GC corto con más frecuencia, aumentando así el rendimiento general. El mundo se detiene, pero por menos tiempo.

El malloc_limit se establece en 8MB fuera de la caja, puede aumentarlo estableciendo el RUBY_GC_MALLOC_LIMIT más alto.

Es su RUBY_GC_MALLOC_LIMIT extremadamente alto? La mía está configurada en 100000000 (100MB). El valor predeterminado es de alrededor de 8MB, pero para las aplicaciones rails recomiendan que sea un poco más alto. Si el tuyo es demasiado alto podría estar evitando que Ruby elimine objetos basura, porque cree que tiene mucho espacio para crecer.

 8
Author: Joe Edgar,
Warning: date(): Invalid date.timezone value 'Europe/Kyiv', we selected the timezone 'UTC' for now. in /var/www/agent_stack/data/www/ajaxhispano.com/template/agent.layouts/content.php on line 61
2013-12-05 04:47:23

Basándome en la explicación de @mudasobwa, finalmente rastreé la causa. El código en CSSPool estaba comprobando el URI de datos muy largo para secuencias de escape. Llamaría a scan en el URI con una expresión regular que coincidiera con una secuencia de escape o un solo carácter, map esos resultados a unescape, y luego join de nuevo en una cadena. Esto estaba asignando efectivamente una cadena para cada carácter en el URI. Lo modifiqué a gsub las secuencias de escape, que parecen tener los mismos resultados (todos las pruebas pasan) y reduce en gran medida la memoria final utilizada.

Usando el mismo caso de prueba que se publicó originalmente (menos la salida Mass.print) este es el resultado antes del cambio:

Memory 12404KB
Memory 292516KB

Y este es el resultado después del cambio:

Memory 12236KB
Memory 19584KB
 8
Author: np_,
Warning: date(): Invalid date.timezone value 'Europe/Kyiv', we selected the timezone 'UTC' for now. in /var/www/agent_stack/data/www/ajaxhispano.com/template/agent.layouts/content.php on line 61
2014-12-04 18:30:27