Carga muy alta, aparentemente causada por pdflush

Carga muy alta, aparentemente causada por pdflush

Tengo un servidor que ejecuta CentOS 5 y periódicamente (un par de veces al día) tendrá enormes picos de carga y todo el servidor se detendrá. Después de un par de minutos, la carga volverá a bajar y todo volverá a la normalidad.

Isospechartiene algo que ver con E/S y tal vez con un disco defectuoso, pero como los discos usan RAID de hardware, no estoy seguro de cómo saber qué está mal (smartctl solo dice "El dispositivo no es compatible con SMART").

De todos modos, lo que veo topes:

top - 08:51:03 up 73 days,  7:45,  1 user,  load average: 69.00, 58.31, 46.89
Tasks: 316 total,   2 running, 314 sleeping,   0 stopped,   0 zombie
Cpu(s): 11.0%us,  1.3%sy,  0.0%ni, 15.2%id, 72.0%wa,  0.0%hi,  0.5%si,  0.0%st
Mem:   8299364k total,  7998520k used,   300844k free,    15480k buffers
Swap: 16779884k total,     4788k used, 16775096k free,  6547860k cached

Como puede ver, la carga es ridículamente alta. Y vmstatmuestra:

procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu------
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
24 16   5632 296080  23392 6317688    0    0     3    28    0    0  7  1 89  3  0
 0 22   5632 292644  23600 6325372    0    0    69 18781 1985 2318  9  2 14 75  0
 1 23   5656 299472  23756 6299140    0    0    44 18667 2075 3382 14  2 13 71  0
 0 23   5656 304756  24152 6295696    0    0    88 17002 1880 1445  4  1 16 78  0
 0 24   5656 296736  24488 6356564    0    0    60 17967 1841  990  2  1 20 76  0
 0 21   5672 302248  24764 6388424    0    0    66 17216 1820  749  2  1 24 73  0

Es el valor "wa" realmente alto lo que me parece extraño. Además, iotopda:

Total DISK READ: 77.37 K/s | Total DISK WRITE: 15.81 M/s
  TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN     IO>    COMMAND                                                                      
25647 be/4 apache     73.50 K/s    0.00 B/s  0.00 % 99.99 % httpd
24387 be/4 root        0.00 B/s    0.00 B/s 99.99 % 99.99 % [pdflush]
23813 be/4 root        0.00 B/s    0.00 B/s  0.00 % 99.99 % [pdflush]
25094 be/4 root        0.00 B/s    0.00 B/s 96.72 % 99.99 % [pdflush]
25093 be/4 root        0.00 B/s    0.00 B/s 99.99 % 99.99 % [pdflush]
25095 be/4 root        0.00 B/s    0.00 B/s 99.99 % 99.99 % [pdflush]
25091 be/4 root        0.00 B/s    0.00 B/s  0.00 % 99.99 % [pdflush]
24389 be/4 root        0.00 B/s    0.00 B/s 99.99 % 99.99 % [pdflush]
24563 be/4 root        0.00 B/s    0.00 B/s 99.99 % 99.99 % [pdflush]
24390 be/4 apache      0.00 B/s   23.21 K/s 96.71 % 99.99 % httpd
24148 be/4 apache      0.00 B/s    0.00 B/s 96.71 % 99.99 % httpd
24699 be/4 apache      0.00 B/s    0.00 B/s 99.99 % 99.99 % httpd
23973 be/4 apache      0.00 B/s    0.00 B/s 99.99 % 99.99 % httpd
24270 be/4 apache      0.00 B/s    0.00 B/s 99.99 % 99.99 % httpd
24298 be/4 apache      0.00 B/s 1918.82 K/s 96.71 % 99.02 % httpd
  628 be/3 root        0.00 B/s    0.00 B/s  0.00 % 97.51 % [kjournald]
25092 be/4 root        0.00 B/s    0.00 B/s  0.00 % 96.72 % [pdflush]
24258 be/4 root        0.00 B/s    0.00 B/s 99.99 % 96.71 % [pdflush]
23814 be/4 root        0.00 B/s    0.00 B/s  0.00 % 96.71 % [pdflush]
24388 be/4 root        0.00 B/s    0.00 B/s 99.02 % 96.71 % [pdflush]
25545 be/4 apache      0.00 B/s    0.00 B/s  0.19 % 92.73 % httpd
25274 be/4 apache      0.00 B/s    0.00 B/s  0.00 % 92.38 % httpd
24801 be/4 apache      0.00 B/s    5.84 M/s 99.99 % 91.63 % httpd
25281 be/4 apache      0.00 B/s    5.75 M/s  0.00 % 91.33 % httpd
26115 be/4 apache      0.00 B/s    0.00 B/s  9.60 % 19.26 % httpd
25561 be/4 apache      0.00 B/s    3.87 K/s  0.00 %  9.66 % httpd
26035 be/4 apache      0.00 B/s    0.00 B/s  0.00 %  9.63 % httpd

Finalmente, obtengo lo siguiente de sar -d 5 0:

Linux 2.6.18-308.1.1.el5PAE (ausbt.com.au)  23/08/12

08:55:45          DEV       tps  rd_sec/s  wr_sec/s  avgrq-sz  avgqu-sz     await     svctm     %util
08:55:50       dev8-0    877.25    103.79  29306.19     33.53    158.81    179.28      1.14     99.84
08:55:50       dev8-1      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
08:55:50       dev8-2      0.00      0.00      0.00      0.00      0.00      0.00      0.00      0.00
08:55:50       dev8-3    877.25    103.79  29306.19     33.53    158.81    179.28      1.14     99.84

Esto ha sucedido recientemente (al menos, lo noté recientemente) y nada en el servidor ha cambiado, por eso sospecho que tal vez haya algún tipo de falla de hardware, pero no estoy seguro de por dónde empezar a buscar.

Actualizar

Gracias a la sugerencia de Mark Wagner, hice un análisis stracede uno de los procesos que realizaba MB/s de E/S y descubrí que estaba escribiendo en archivos llamados "/tmp/magick-XXXXXXX". Aquí está el resultado de `ls -l /tmp/magick-XX*":

-rw------- 1 apache apache 1854881318400 Aug 20 04:26 /tmp/magick-XXrQahSe
-rw------- 1 apache apache 1854881318400 Aug 20 04:26 /tmp/magick-XXTaXatz
-rw------- 1 apache apache 1854881318400 Aug 20 04:26 /tmp/magick-XXtf25pe

¡Guau! Esos archivos eran de hace un par de días, pero también hay archivos de hoy que tienen un tamaño similar. Mi código genera dinámicamente miniaturas de imágenes usando ImageMagick, por lo que tal vez haya una imagen corrupta en algún lugar que esté causando que ImageMagick se asuste y escriba archivos de 1,6 terrabytes en /tmp.

Investigaré un poco más y publicaré una actualización cuando encuentre más. Gracias a todos por las sugerencias hasta ahora.

Respuesta1

Comentario convertido en respuesta.

Los PID de Apache 24801 y 25281 son, con diferencia, los que realizan la mayor cantidad de E/S: 5,84 M/s y 5,75 M/s, respectivamente. Utilizo iotop -opara excluir procesos que no realizan E/S.

Respuesta2

No estoy seguro de si puedes confiar en iotop ya que no estás en un nivel de kernel con el que sea compatible.

Estoy en el mismo kernel (2.6.18) que tú y no puedo hacer que iotop -o funcione... no me muestra solo los procesos de producción de IO.

información relacionada