Temos quatro servidores Linux idênticos com uma grande partição de disco rígido (5T). Nós temos o Linux Scientific com este kernel:
Linux s3.law.di.unimi.it 2.6.32-358.18.1.el6.x86_64 #1 SMP Tue Aug 27 14:23:09 CDT 2013 x86_64 x86_64 x86_64 GNU/Linux
Os servidores são configurados de forma idêntica, instalados, etc. Mas um, e apenas um dos servidores, é ridiculamente lento ao escrever com o ext4. Se eu fizer um
dd if=/dev/zero of=/mnt/big/analysis/test
l -tr
total 11M
-rw-r--r-- 1 root root 11M Apr 20 10:01 test
10:01:42 [s3] /mnt/big/analysis
l -tr
total 16M
-rw-r--r-- 1 root root 16M Apr 20 10:02 test
10:02:13 [s3] /mnt/big/analysis
Então, 5MB em 30s Todos os outros servidores escrevem mais de uma ordem de magnitude mais rápido.
As máquinas têm 64 GB, 32 núcleos e não têm I / O ou atividade de CPU, embora 90% da memória seja preenchida por um grande processo Java que não faz nada. Apenas uma máquina está escrevendo lentamente.
SMART diz que tudo está OK
# smartctl -H /dev/sdb
smartctl 5.42 2011-10-20 r3458 [x86_64-linux-2.6.32-358.18.1.el6.x86_64] (local build)
Copyright (C) 2002-11 by Bruce Allen, http://smartmontools.sourceforge.net
SMART Health Status: OK
o hdparm lê sem problemas:
# hdparm -t /dev/sdb
/dev/sdb:
Timing buffered disk reads: 1356 MB in 3.00 seconds = 451.60 MB/sec
A partição é montada da seguinte forma:
/dev/sdb1 on /mnt/big type ext4 (rw,noatime,data=writeback)
e nós definimos
tune2fs -o journal_data_writeback /dev/sdb1
para desempenho.
Eu tentei encontrar qualquer coisa que pudesse explicar por que esse servidor específico escreve tão lentamente, ou seja, qualquer diferença na saída de uma ferramenta de diagnóstico, sem resultados.
Só para completar a imagem: começamos em todos os servidores um rastreamento, partições essencialmente vazias. O rastreamento criou vários arquivos na partição e, em particular, um arquivo 156G (o armazenamento do rastreamento). O rastreamento começou OK, mas depois de algumas horas vimos lentidão (aparentemente, como a loja estava crescendo). Quando verificamos, percebemos que gravar no disco estava ficando mais lento e mais lento e mais lento.
Paramos tudo - sem atividade da CPU, sem E / S - mas ainda assim o dd estava mostrando o comportamento acima. Os outros três servidores, em condições idênticas, os mesmos arquivos, etc., funcionam perfeitamente, tanto durante o rastreamento quanto no uso do dd.
Francamente, eu nem sei onde procurar. Alguém ouve um sino tocando? Quais ferramentas de diagnóstico eu posso usar para entender o que está acontecendo ou quais testes devo testar?
Atualizar
Ao lado do link postado, achei que seria uma boa ideia realizar os mesmos testes em dois servidores que estavam executando o rastreador. É interessante. Por exemplo, o vmstat 10 fornece
Bom
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
4 0 68692 9009864 70832 29853400 0 0 15 214 9 2 11 1 88 0 0
10 0 68692 8985620 70824 29883460 0 0 48 7402 79465 62898 12 1 86 0 0
11 0 68692 8936780 70824 29928696 0 0 54 6842 81500 66665 15 1 83 0 0
10 2 68692 8867280 70840 30000104 0 0 65 36578 80252 66272 14 1 85 0 0
15 0 68692 8842960 70840 30026724 0 0 61 3667 81245 65161 14 1 85 0 0
Ruim
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
13 0 8840 14015100 92972 25683108 0 0 11 104 3 9 4 1 94 0 0
2 0 8840 14015800 92984 25696108 0 0 49 16835 38619 54204 2 2 96 0 0
1 0 8840 14026004 93004 25699940 0 0 33 4152 25914 43530 0 2 98 0 0
1 0 8840 14032272 93012 25703716 0 0 30 1164 25062 43230 0 2 98 0 0
2 0 8840 14029632 93020 25709448 0 0 24 5619 23475 40080 0 2 98 0 0
E iostat -x -k 5
Bom
Linux 2.6.32-358.18.1.el6.x86_64 (s0.law.di.unimi.it) 04/21/2014 _x86_64_ (64 CPU)
avg-cpu: %user %nice %system %iowait %steal %idle
10.65 0.00 1.02 0.11 0.00 88.22
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
sdb 0.11 3338.25 17.98 56.52 903.55 13579.19 388.79 7.32 98.30 1.23 9.18
sda 0.39 0.72 0.49 0.76 11.68 5.90 28.25 0.01 11.25 3.41 0.43
avg-cpu: %user %nice %system %iowait %steal %idle
15.86 0.00 1.33 0.03 0.00 82.78
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
sdb 0.00 1106.20 9.20 31.00 36.80 4549.60 228.18 0.41 10.09 0.39 1.58
sda 0.00 2.20 0.80 3.00 4.80 20.80 13.47 0.04 10.53 3.21 1.22
avg-cpu: %user %nice %system %iowait %steal %idle
15.42 0.00 1.23 0.01 0.00 83.34
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
sdb 0.00 1205.40 8.00 33.60 40.80 4956.00 240.23 0.39 9.43 0.33 1.38
sda 0.00 0.60 0.00 1.00 0.00 6.40 12.80 0.01 5.20 4.20 0.42
Ruim
Linux 2.6.32-358.18.1.el6.x86_64 (s2.law.di.unimi.it) 04/21/2014 _x86_64_ (64 CPU)
avg-cpu: %user %nice %system %iowait %steal %idle
4.37 0.00 1.41 0.06 0.00 94.16
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
sdb 0.06 1599.70 13.76 38.23 699.27 6551.73 278.96 3.12 59.96 0.99 5.16
sda 0.46 3.17 1.07 0.78 22.51 15.85 41.26 0.03 16.10 2.70 0.50
avg-cpu: %user %nice %system %iowait %steal %idle
11.93 0.00 2.99 0.60 0.00 84.48
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
sdb 0.00 14885.40 13.60 141.20 54.40 60106.40 777.27 34.90 225.45 1.95 30.14
sda 0.00 0.40 0.00 0.80 0.00 4.80 12.00 0.01 7.00 3.25 0.26
avg-cpu: %user %nice %system %iowait %steal %idle
11.61 0.00 2.51 0.16 0.00 85.71
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
sdb 0.00 2245.40 10.60 51.20 42.40 9187.20 298.69 3.51 56.80 2.04 12.58
sda 0.00 0.40 0.00 0.80 0.00 4.80 12.00 0.01 6.25 3.25 0.26
Então (se eu entendi corretamente a saída) parece que, sim, como ficou aparente nos rastreios da pilha da JVM, o servidor lento está demorando para fazer I / O. Resta entender o porquê: (.
Eu também executei um strace -c ls -R / . Eu não sabia que tinha que correr por um tempo, então os dados anteriores não são muito significativos. O comando foi executado enquanto o rastreador estava sendo executado , portanto, com E / S massiva em andamento.
Bom
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
99.62 14.344825 114 126027 getdents
0.25 0.036219 1 61812 12 open
0.07 0.009891 0 61802 close
0.06 0.007975 0 61801 fstat
0.01 0.000775 0 8436 write
0.00 0.000043 22 2 rt_sigaction
0.00 0.000000 0 12 read
0.00 0.000000 0 1 stat
0.00 0.000000 0 3 1 lstat
0.00 0.000000 0 33 mmap
0.00 0.000000 0 16 mprotect
0.00 0.000000 0 4 munmap
0.00 0.000000 0 15 brk
0.00 0.000000 0 1 rt_sigprocmask
0.00 0.000000 0 3 3 ioctl
0.00 0.000000 0 1 1 access
0.00 0.000000 0 3 mremap
0.00 0.000000 0 1 execve
0.00 0.000000 0 1 fcntl
0.00 0.000000 0 1 getrlimit
0.00 0.000000 0 1 statfs
0.00 0.000000 0 1 arch_prctl
0.00 0.000000 0 3 1 futex
0.00 0.000000 0 1 set_tid_address
0.00 0.000000 0 1 set_robust_list
------ ----------- ----------- --------- --------- ----------------
100.00 14.399728 319982 18 total
Ruim
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
99.81 24.210936 181 133618 getdents
0.14 0.032755 1 63183 14 open
0.03 0.006637 0 63171 close
0.02 0.005410 0 63170 fstat
0.00 0.000434 0 15002 write
0.00 0.000000 0 12 read
0.00 0.000000 0 1 stat
0.00 0.000000 0 4 1 lstat
0.00 0.000000 0 33 mmap
0.00 0.000000 0 16 mprotect
0.00 0.000000 0 4 munmap
0.00 0.000000 0 25 brk
0.00 0.000000 0 2 rt_sigaction
0.00 0.000000 0 1 rt_sigprocmask
0.00 0.000000 0 3 3 ioctl
0.00 0.000000 0 1 1 access
0.00 0.000000 0 3 mremap
0.00 0.000000 0 1 execve
0.00 0.000000 0 1 fcntl
0.00 0.000000 0 1 getrlimit
0.00 0.000000 0 1 statfs
0.00 0.000000 0 1 arch_prctl
0.00 0.000000 0 3 1 futex
0.00 0.000000 0 1 set_tid_address
0.00 0.000000 0 1 set_robust_list
------ ----------- ----------- --------- --------- ----------------
100.00 24.256172 338259 20 total