Alta carga del servidor - [jbd2 / md1-8] usando 99.99% IO

12

He tenido un pico en la carga durante la última semana. Esto generalmente ocurre una o dos veces al día. He logrado identificar desde iotop que [jbd2 / md1-8] está utilizando 99.99% IO. Durante los tiempos de alta carga no hay mucho tráfico al servidor.

Las especificaciones del servidor son:

  • AMD Opteron 8 core
  • 16 GB de RAM
  • 2x2.000 GB 7.200 RPM HDD Software Raid 1
  • Cloudlinux + Cpanel
  • Mysql está sintonizado correctamente

Además de los picos, la carga suele ser de alrededor de 0,80 como máximo.

He buscado alrededor pero no puedo encontrar lo que [jbd2 / md1-8] hace exactamente. ¿Alguien ha tenido este problema o alguien conoce una posible solución?

Gracias.

ACTUALIZAR:

TIME        TID     PRIO     USER    DISK READ    DISK WRITE    SWAPIN  IO       COMMAND
16:05:36     399     be/3    root    0.00 B/s      38.76 K/s    0.00 %  99.99 %  [jbd2/md1-8]
Alex
fuente
1
en.wikipedia.org/wiki/Journaling_block_device & linux.die.net/man/4/md apuntan a que esto está relacionado con el software RAID.
mbrownnyc
Gracias por su respuesta. Después de investigar un poco, descubrí que está relacionado con el software RAID. ¿Conoces alguna solución? Lo extraño que comenzó a ocurrir hace solo una semana, después de casi 3 meses sin problemas.
Alex
¿Cómo determinó que el IO es 99.99%? ¿Usaste iostat? ¿Puedes correr un poco de eso (por ejemplo iostat 5) por un momento y compartir la salida?
slm
Habilité el registro para iotop y miré el registro durante el intervalo en que ocurrió la carga. Ahora la carga es baja, por lo que no tiene sentido ejecutarla ahora, pero lo haré la próxima vez que ocurra. Gracias por su respuesta.
Alex
1
Me encontré con este problema exacto. ¿Cuál fue su solución final?
Satanicpuppy

Respuestas:

18

Esto no es realmente una respuesta, ya que no hay suficiente contexto para dar la causa exacta, pero es una descripción de cómo logré rastrear esto cuando me sucedió.

Noté que jbd2/md0-8seguía apareciendo en la parte superior iotop. Miré /sys/kernel/debug/tracing/events/jbd2para ver qué opciones hay para determinar qué jbd2estaba haciendo.

NOTA-1: Para ver la salida de los eventos de seguimiento de depuración cat /sys/kernel/debug/tracing/trace_pipe: hice que se ejecutara en la terminal al habilitar / deshabilitar los seguimientos.

NOTA-2: Para habilitar eventos para el uso de rastreo, por ejemplo echo 1 > /sys/kernel/debug/tracing/events/jbd2/jbd2_run_stats/enable. Para desactivar echo 0 > /sys/kernel/debug/tracing/events/jbd2/jbd2_run_stats/enable.

Comencé habilitando /sys/kernel/debug/tracing/events/jbd2/jbd2_run_stats/enable, pero no había nada que pareciera particularmente interesante en el resultado. Intenté rastrear algunos otros eventos y cuando lo habilité /sys/kernel/debug/tracing/events/jbd2/jbd2_commit_flushing/enable, vi que ocurría cada segundo:

# cat /sys/kernel/debug/tracing/trace_pipe
...
jbd2/md0-8-2520  [004] .... 658660.216492: jbd2_commit_flushing: dev 9,0 transaction 32856413 sync 0
jbd2/md0-8-2520  [001] .... 658661.334900: jbd2_commit_flushing: dev 9,0 transaction 32856414 sync 0
jbd2/md0-8-2520  [001] .... 658661.394113: jbd2_commit_flushing: dev 9,0 transaction 32856415 sync 0

Esto parecía estar relacionado con sync(2)/ fsync(2)/ msync(2), así que busqué alguna forma de vincular esto con un proceso y encontré esto:

# find /sys/kernel/debug/tracing/events/ | grep sync.*enable
...
/sys/kernel/debug/tracing/events/ext4/ext4_sync_file_enter/enable
...

Cuando lo habilité, vi el siguiente resultado:

# cat /sys/kernel/debug/tracing/trace_pipe
...
      nzbget-17367 [002] .... 658693.222288: ext4_sync_file_enter: dev 9,0 ino 301924373 parent 301924357 datasync 1 
  jbd2/md0-8-2520  [001] .... 658693.284080: jbd2_commit_flushing: dev 9,0 transaction 32856465 sync 0
      nzbget-17367 [000] .... 658693.334267: ext4_sync_file_enter: dev 9,0 ino 301924357 parent 301924353 datasync 1 
  jbd2/md0-8-2520  [002] .... 658693.334275: jbd2_commit_flushing: dev 9,0 transaction 32856466 sync 0
      nzbget-17367 [001] .... 658694.369514: ext4_sync_file_enter: dev 9,0 ino 301924367 parent 301924357 datasync 1 
  jbd2/md0-8-2520  [002] .... 658694.414861: jbd2_commit_flushing: dev 9,0 transaction 32856467 sync 0
      nzbget-17367 [001] .... 658694.470872: ext4_sync_file_enter: dev 9,0 ino 301924357 parent 301924353 datasync 1 
  jbd2/md0-8-2520  [002] .... 658694.470880: jbd2_commit_flushing: dev 9,0 transaction 32856468 sync 0

Esto me dio el nombre / id del proceso, y después de hacer un poco más de depuración de este proceso ( nzbget) descubrí que estaba haciendo fsync(2)cada segundo. Después de que cambié su configuración ( FlushQueue=nocreo que no documentado, lo encontré en la fuente) para evitar que hiciera esto por segundo, fsync(2)el problema desapareció.

Mi versión del kernel es 4.4.6-gentoo. Creo que hubo algunas opciones que habilité (ya sea manualmente o con make oldconfig) en algún momento de la configuración del kernel para obtener /sys/kernel/debugestos eventos, así que si no lo tiene, simplemente busque en Internet para obtener más información sobre cómo habilitar eso.

Iwan Aucamp
fuente
Buen detective. Esto es muy útil.
jdhildeb
¡Muchas gracias por detallar todo el proceso!
astrojuanlu
1

Esto parece ser una actualización relacionada con la revista. ¿De cuántos discos está compuesto el software RAID? ¿Me puede mostrar el comando utilizado para crearlo?

¿Puedes pegar también la salida dumpe2fs? Primero, identifique el dispositivo físico donde ve carga. Use df para saber esto. Entonces,

dumpe2fs /dev/sdaX > /tmp/dump

Para su caso, podría ser / dev / md0.

Además, ejecuta esto.

iostat -xdk 1 25

En el momento del alto problema de IO.

No conozco cloudlinux pero es la herramienta blktrace disponible debajo de ella

Soham Chakraborty
fuente
Hola Soham, gracias por tu respuesta. Hay 2 discos en la matriz. En cuanto a dumpe2fs, ¿puede darme el comando completo que desea que ejecute? Gracias por ayudar.
Alex
Alex, editó la respuesta.
Soham Chakraborty
Nunca olvides que esto no es realmente una configuración de perforación media incluso de los discos - "lento como una estación de trabajo" lo describe más.
TomTom