Servidor de correo con carga desproporcionada.
Muy buenas,
hace 8 dias que hemos hecho la migración de nuestro servidor de correo
a una màquina en teoria el doble de potente, con 4 procesadores de
64bits, cerca de 3 GB de memoria principal y un disco scsi sobrado de
capacidad. El servidor corre con debian etch (el otro server andaba
con sarge) y en principio la configuración de sendmail, greylist,
mailman, mailscan.. es la misma (mismos ficheros). Cual és la sorpresa
al ver multiplicada por 10 la carga del sistema. Top del servidor en
estos momentos ordenado por tiempo de CPU:
top - 11:50:35 up 8 days, 41 min, 4 users, load average: 27.60, 23.70, 20.70
Tasks: 332 total, 1 running, 331 sleeping, 0 stopped, 0 zombie
Cpu(s): 9.3%us, 5.6%sy, 4.6%ni, 59.2%id, 20.6%wa, 0.0%hi , 0.7%si, 0.0%st
Mem: 3609552k total, 3532124k used, 77428k free, 36472k buffers
Swap: 3421804k total, 388360k used, 3033444k free, 1070116k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM
TIME+ COMMAND
4689 smmsp 15 0 541m 307m 764 S 55 8.7
785:09.68 milter-greylist
2941 bind 25 0 162m 94m 2288 S 2 2.7
226: 25.61 named
2382 root 10 -5 0 0 0 D 2
0.0 193:32.43 kjournald
3008 root 18 0 8764 2292 492 S 1 0.1
136:34.00 ypserv
2524 daemon 15 0 4824 524 404 S 0 0.0
26:56.27 portmap
2923 root 15 0 3732 644 504 S 0
0.0 26:04.08 syslogd
32065 root 15 0 26656 3188 1144 S 0 0.1
24:41.08 mailgraph
3230 list 15 0 99.5m 65m 2656 S 0 1.9
11:25.18 python
Cabe decir que en las horas puntas la carga es normalmente de 30 y
puntualmente llega a 40. Sospechamos que la mayor parte de esta carga
es devida a e/s y no a consumo directo de cpu. Para reforzar esta
hipotesis vease la salida del iostat:
avg-cpu: %user %nice %system %iowait %steal %idle
12.66 2.02 6.22 18.59 0.00 60.51
Device: tps Blk_read/s Blk_wrtn/s Blk_read Blk_wrtn
sdb 183.20 4430.01 5645.12 3070765888 3913049312
dm-0 6.72 2.30 52.20 1596538 36183240
dm-1 4.56 9.40 31.63 6517202 21921904
dm-2 1.00 0.04 8.02 30706 5558944
dm-3 9.75 582.40 9.54 403703138 6616088
dm-4 733.34 3833.01 5539.01 2656938362 3839493792
Entre lecturas y escrituras estamos sumando una velocidad de 10mil
bloques por segundo en un mismo disco, Ami me da la sensación de que
esto es el límite de nuestro disco scsi, con lo que estaria haciendo
de cuello de botella de nuestro sistema, estimulando su carga (seria
interesante conocer las especificaciones en cuanto a ancho de banda
del dispositivo... )
¿que es lo que está trasteando el sistema con tantos bloques de disco?
Veamos otro top, ahora ordenado por ocupación en memória.
top - 12:17:59 up 8 days, 1:09, 4 users, load average: 18.98, 21.06, 21.81
Tasks: 352 total, 1 running, 351 sleeping, 0 stopped, 0 zombie
Cpu(s): 7.0%us, 5.0%sy, 2.3%ni, 60.0%id, 25.1%wa, 0.1%hi, 0.6%si, 0.0%st
Mem: 3609552k total, 3536432k used, 73120k free, 87548k buffers
Swap: 3421804k total, 246348k used, 3175456k free, 1362388k cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
4689 smmsp 15 0 445m 307m 764 S 23 8.7 794:41.17
milter-greylist
3228 list 15 0 304m 184m 2568 S 0 5.2 6:20.05 python
2941 bind 25 0 162m 94m 2288 S 2 2.7 226:58.16 named
13077 root 17 2 146m 88m 2320 S 2 2.5 0:00.36
MailScanner
13088 root 17 2 145m 87m 1996 S 1 2.5 0:00.28
MailScanner
13434 root 18 2 145m 87m 1936 S 0 2.5 0:00.46
MailScanner
13238 root 17 2 145m 87m 1920 S 0 2.5 0:00.16
MailScanner
12476 root 17 2 144m 86m 1992 S 0 2.5 0:00.13
MailScanner
25410 root 17 2 143m 86m 3256 S 0 2.5 0:02.04
MailScanner
21922 root 20 2 143m 86m 3232 S 2 2.5 0:02.09
MailScanner
22662 root 20 2 142m 85m 3232 S 0 2.4 0:01.97
MailScanner
20543 root 19 2 143m 85m 3232 D 0 2.4 0:02.20
MailScanner
26116 root 18 2 142m 85m 3232 S 0 2.4 0:01.76
MailScanner
23977 root 20 2 142m 85m 3256 S 0 2.4 0:01.97
MailScanner
23330 root 20 2 142m 85m 3256 S 0 2.4 0:02.27
MailScanner
24641 root 18 2 142m 85m 3232 S 0 2.4 0:01.78
MailScanner
13204 root 17 2 143m 85m 1756 S 0 2.4 0:00.12
MailScanner
21181 root 17 2 142m 85m 3256 S 0 2.4 0:02.09
MailScanner
26831 root 20 2 142m 85m 3232 S 0 2.4 0:01.88
MailScanner
3232 list 15 0 93132 55m 2692 S 0 1.6 6:36.19 python
Nuestro amigo MailScanner tiene 16 hijos de 144Mb cada uno. Esto se
traduce a un total de 2.3Gb de memoria principal para un solo proceso.
Y si a esto se le suma la embergadura de su compañero de trabajo
Greylist, en que normalmente ronda los 500MB, vemos que ellos dos
solos ya se estan comiendo toda la Memoria principal y más. Obligando
al sistema a swapear mas o menos 400MB, con el trashing que comporta.
¿Es normal un uso indiscriminado de memoria por parte de mailscanner?
¿Que más ocurre en el sistema?
Viendo los logs de sendmail nos damos cuenta de que que en apenas 5
horas (de 7:30 a 12:30) ha escrito 3x371MB:
-rw-r----- 1 root adm 371M 2007-07-19 07:32 mail.log.0
-rw-r----- 1 root adm 371M 2007-07-19 07:32 mail.info.0
-rw-r----- 1 root adm 371M 2007-07-19 07:32 syslog.0
¿Que le esta pasando al servicio de mail para reportar en 5 horas casi
400Mb en logs? Mi compañero ha observado un monton de errores del tipo
siguiente:
Jul 18 07:47:50 avant sendmail[4239]: l6I3XI9H031999: to=positius,
delay=02:14:26, xdelay=00:00:00, mailer=local, pri=44404943,
dsn=4.0.0, stat=Deferred: local mailer (/usr/sbin/sensible-mda) exited
with EX_TEMPFAIL
concretamente: 670864 en 5 horas, es decir 37.27 errores/segundo. WoW.
EX_TEMPFAIL indica que el usuario a superado la cuota y el mensage no
puede entregarse. Con lo que suponemos que el servidor reintenta el
envio. Concretamente para un usuario en concreto, estos intentos de
reenvio se han reportado un total de 29345 veces.
¿Es todo esto normal? ¿hemos llegado al final de la questión? ¿Que
solución se os ocurren para esotos 'posibles' problemas?
Saludos y muchisimas gracias por haber leido hasta aquí ;)
Marc.
Reply to: