Alta carga média, baixo uso da CPU - por quê?

72

Estamos vendo enormes problemas de desempenho em um aplicativo da web e estamos tentando encontrar o gargalo. Eu não sou um administrador de sistemas, então há algumas coisas que eu não entendo. Algumas investigações básicas mostram que a CPU está ociosa, muita memória disponível, sem troca, sem E / S, mas com uma carga média alta.

A pilha de software neste servidor é assim:

  • Solaris 10
  • Java 1.6
  • WebLogic 10.3.5 (8 domínios)

Os aplicativos em execução neste servidor falam com um banco de dados Oracle em um servidor diferente.

Este servidor tem 32GB de RAM e 10 CPUs (eu acho).

A execução de prstat -Z apresenta algo assim:

   PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/NLWP
  3836 ducm0101 2119M 2074M cpu348  58    0   8:41:56 0.5% java/225
 24196 ducm0101 1974M 1910M sleep   59    0   4:04:33 0.4% java/209
  6765 ducm0102 1580M 1513M cpu330   1    0   1:21:48 0.1% java/291
 16922 ducm0102 2115M 1961M sleep   58    0   6:37:08 0.0% java/193
 18048 root     3048K 2440K sleep   59    0   0:06:02 0.0% sa_comm/4
 26619 ducm0101 2588M 2368M sleep   59    0   8:21:17 0.0% java/231
 19904 ducm0104 1713M 1390M sleep   59    0   1:15:29 0.0% java/151
 27809 ducm0102 1547M 1426M sleep   59    0   0:38:19 0.0% java/186
  2409 root       15M   11M sleep   59    0   0:00:00 0.0% pkgserv/3
 27204 root       58M   54M sleep   59    0   9:11:38 0.0% stat_daemon/1
 27256 root       12M 8312K sleep   59    0   7:16:40 0.0% kux_vmstat/1
 29367 root      297M  286M sleep   59    0  11:02:13 0.0% dsmc/2
 22128 root       13M 6768K sleep   59    0   0:10:51 0.0% sendmail/1
 22133 smmsp      13M 1144K sleep   59    0   0:01:22 0.0% sendmail/1
 22003 root     5896K  240K sleep   59    0   0:00:01 0.0% automountd/2
 22074 root     4776K 1992K sleep   59    0   0:00:19 0.0% sshd/1
 22005 root     6184K 2728K sleep   59    0   0:00:31 0.0% automountd/2
 27201 root     6248K  344K sleep   59    0   0:00:01 0.0% mount_stat/1
 20964 root     2912K  160K sleep   59    0   0:00:01 0.0% ttymon/1
 20947 root     1784K  864K sleep   59    0   0:02:22 0.0% utmpd/1
 20900 root     3048K  608K sleep   59    0   0:00:03 0.0% ttymon/1
 20979 root       77M   18M sleep   59    0   0:14:13 0.0% inetd/4
 20849 daemon   2856K  864K sleep   59    0   0:00:03 0.0% lockd/2
 17794 root       80M 1232K sleep   59    0   0:06:19 0.0% svc.startd/12
 17645 root     3080K  728K sleep   59    0   0:00:12 0.0% init/1
 17849 root       13M 6800K sleep   59    0   0:13:04 0.0% svc.configd/15
 20213 root       84M   81M sleep   59    0   0:47:17 0.0% nscd/46
 20871 root     2568K  600K sleep   59    0   0:00:04 0.0% sac/1
  3683 ducm0101 1904K 1640K sleep   56    0   0:00:00 0.0% startWebLogic.s/1
 23937 ducm0101 1904K 1640K sleep   59    0   0:00:00 0.0% startWebLogic.s/1
 20766 daemon   5328K 1536K sleep   59    0   0:00:36 0.0% nfsmapid/3
 20141 daemon   5968K 3520K sleep   59    0   0:01:14 0.0% kcfd/4
 20093 ducm0101 2000K  376K sleep   59    0   0:00:01 0.0% pfksh/1
 20797 daemon   3256K  240K sleep   59    0   0:00:01 0.0% statd/1
  6181 root     4864K 2872K sleep   59    0   0:01:34 0.0% syslogd/17
  7220 ducm0104 1268M 1101M sleep   59    0   0:36:35 0.0% java/138
 27597 ducm0102 1904K 1640K sleep   59    0   0:00:00 0.0% startWebLogic.s/1
 27867 root       37M 4568K sleep   59    0   0:13:56 0.0% kcawd/7
 12685 ducm0101 4080K  208K sleep   59    0   0:00:01 0.0% vncconfig/1
ZONEID    NPROC  SWAP   RSS MEMORY      TIME  CPU ZONE
    42      135   22G   19G    59%  87:27:59 1.2% dsuniucm01

Total: 135 processes, 3167 lwps, load averages: 54.48, 62.50, 63.11

Eu entendo que a CPU está quase inativa, mas a média de carga é alta, o que é muito estranho para mim. A memória não parece ser um problema.

A execução de vmstat 15 apresenta algo assim:

 kthr      memory            page            disk          faults      cpu
 r b w   swap  free  re  mf pi po fr de sr s0 s1 s4 sd   in   sy   cs us sy id
 0 0 0 32531400 105702272 317 1052 126 0 0 0 0 13 13 -0 8 9602 107680 10964 1 1 98
 0 0 0 15053368 95930224 411 2323 0 0 0 0 0 0  0  0  0 23207 47679 29958 3 2 95
 0 0 0 14498568 95801960 3072 3583 0 2 2 0 0 3 3  0 21 22648 66367 28587 4 4 92
 0 0 0 14343008 95656752 3080 2857 0 0 0 0 0 3 3  0 18 22338 44374 29085 3 4 94
 0 0 0 14646016 95485472 1726 3306 0 0 0 0 0 0 0  0  0 24702 47499 33034 3 3 94

Eu entendo que a CPU está praticamente inativa, nenhum processo está esperando na fila para ser executado, pouca troca está acontecendo.

A execução de iostat 15 fornece isso:

   tty        sd0           sd1           sd4           ssd0           cpu
 tin tout kps tps serv  kps tps serv  kps tps serv  kps tps serv   us sy wt id
   0  676 324  13    8  322  13    8    0   0    0  159   8    0    1  1  0 98
   1 1385   0   0    0    0   0    0    0   0    0    0   0    0    3  4  0 94
   0  584  89   6   24   89   6   25    0   0    0  332  19    0    2  1  0 97
   0  296   0   0    0    0   0    0    0   0    0    0   0    0    2  2  0 97
   1 1290  43   5   24   43   5   22    0   0    0  297  20    1    3  3  0 94

A execução de netstat -i 15 fornece o seguinte:

    input   aggr26    output       input  (Total)    output
packets errs  packets errs  colls  packets errs  packets errs  colls
1500233798 0     1489316495 0     0      3608008314 0     3586173708 0     0
10646   0     10234   0     0      26206   0     25382   0     0
11227   0     10670   0     0      28562   0     27448   0     0
10353   0     9998    0     0      29117   0     28418   0     0
11443   0     12003   0     0      30385   0     31494   0     0

O que estou perdendo?

    
por Spiff 29.02.2012 / 23:29

6 respostas

39

Com mais algumas investigações, parece que o problema de desempenho é principalmente devido a um alto número de chamadas de rede entre dois sistemas (Oracle SSXA e UCM). As chamadas são rápidas, mas abundantes e serializadas, portanto, o baixo uso da CPU (principalmente esperando pela E / S), a alta carga média (muitas chamadas esperando para serem processadas) e especialmente os longos tempos de resposta (pelo acúmulo de pequenos tempos de resposta).

Obrigado pela sua visão sobre este problema!

    
por 02.03.2012 / 16:15
30

Quando você diz 'Alta carga média', eu suponho que você quer dizer que o prstat é exibido para 'load average' na parte inferior dos valores de saída de

Total: 135 processes, 3167 lwps, load averages: 54.48, 62.50, 63.11

Esses números são parecidos com os que o topo fornece e provavelmente significam o tamanho médio da fila do processo em execução. Esta não é a porcentagem do tempo do processador sendo usado, mas quantas 'coisas' estão assediando a CPU para o tempo de execução. Evidentemente, estes parecem bastante elevados, mas tudo isso depende do aplicativo que você está executando; os processos podem não estar realmente fazendo muito quando eles obtêm seu slot. Veja aqui para uma boa explicação sobre o top.

Não estou familiarizado com o WebLogic, mas notei que, geralmente, com o Apache Tomcat, muitos encadeamentos Java podem ser gerados simultaneamente para o que aparece como não muitos pedidos. Pode ser isso que está causando esses altos números de carga média. Certifique-se de estar usando o pool de conexão onde for apropriado para conectar-se ao backend e considere aumentar o número de encadeamentos ociosos que estão disponíveis para seu aplicativo manipular conexões (não sabe como fazer isso no WebLogic; o Tomcat tem um pool de encadeamentos por conector ou um conjunto de encadeamentos do executor geral). Se você não fizer isso, novos tópicos podem estar sendo gerados para processar solicitações.

Quanto ao desempenho, você precisa descobrir o que parte do seu aplicativo está sofrendo. É o processamento que está acontecendo no lado WebLogic / Java, o acesso ao banco de dados, pesquisas de DNS (se estão sendo feitas por algum motivo ...), problemas de rede ou algo no sistema operacional.

99% das vezes será o seu código e como ele fala com o banco de dados que está segurando as coisas. Em seguida, será a configuração do aplicativo da web. Depois desse ponto, você estará trabalhando para extrair os últimos milésimos de segundo do seu aplicativo ou para fornecer maior concorrência com o mesmo hardware. Para esse ajuste de desempenho mais refinado, você precisa de métricas.

Para Java, sugiro instalar a Java Melody . Ele pode fornecer muitas informações sobre o que seu programa está fazendo e ajudar a diminuir o tempo gasto. Eu usei-o apenas com o Tomcat, mas deve funcionar bem com qualquer coisa de contêiner / servlet do Java EE.

Existem várias maneiras de ajustar o Java, então dê uma olhada em suas diretrizes de desempenho (tenho certeza que você provavelmente tem) e verifique se você está definindo o tamanho de heap correto, etc., adequado para o seu programa. O Java Melody pode ajudá-lo a rastrear o tamanho do heap do Java que você está consumindo, além de quão difícil o coletor de lixo está funcionando / com que frequência ele está interrompendo seu programa para limpar objetos.

Espero que tenha sido útil. Se você fornecer mais informações, poderei atualizar essa resposta e aprimorá-la de acordo com suas necessidades.

    
por 01.03.2012 / 01:36
19

Como nota à parte, a média de carga também inclui itens aguardando atividade de disco (isto é, assediar o disco), bem como os que aguardam pelo cpu, é uma soma de ambos ... então você pode ter problemas em um ou outro.

Veja "O Linux também inclui [em sua média de carga] processos em estados de suspensão ininterruptos (geralmente esperando para atividade de disco) "

Como nota de rodapé, o problema específico com que me deparei foi que eu tinha alta carga média, mas também muita CPU ociosa e baixo uso de disco.

Parece que, pelo menos no meu caso, às vezes os threads / processos aguardando E / S aparecem na média de carga, mas não causam um aumento na coluna "await". Mas eles ainda estão ligados a E / S.

Você pode dizer que este é o caso com o seguinte código, se você executá-lo em jruby (apenas 100 threads com lotes de E / S cada):

100.times { Thread.new { loop { File.open('big', 'w') do |f| f.seek 10_000_000_000; f.puts 'a'; end}}}

O que dá uma saída principal como esta:

top - 17:45:32 up 38 days,  2:13,  3 users,  load average: 95.18, 50.29, 23.83
Tasks: 181 total,   1 running, 180 sleeping,   0 stopped,   0 zombie
Cpu(s):  3.5%us, 11.3%sy,  0.0%ni, 85.1%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:  32940904k total, 23239012k used,  9701892k free,   983644k buffers
Swap: 34989560k total,        0k used, 34989560k free,  5268548k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
31866 packrd    18   0 19.9g  12g  11m S 117.0 41.3   4:43.85 java
  912 root      11  -5     0    0    0 S  2.0  0.0   1:40.46 kjournald

Assim, você pode ver que há muita CPU ociosa, 0,0% de wa, mas uma média de carga muito alta.

iostat mostra o disco como basicamente ocioso:

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
       9.62    0.00    8.75    0.00    0.00   81.62

Device:         rrqm/s   wrqm/s   r/s   w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.00    49.00  0.00  6.40     0.00   221.60    69.25     0.01    0.81   0.66   0.42
sda1              0.00    49.00  0.00  6.40     0.00   221.60    69.25     0.01    0.81   0.66   0.42
sda2              0.00     0.00  0.00  0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

veja também link

Como uma nota adicional, isso também parece implicar que (pelo menos neste caso - rodando o CentOS) a média de carga inclui cada thread separadamente no total.

    
por 19.07.2013 / 19:46
6

Tive o mesmo problema hoje. Depois de algumas pesquisas e diagnósticos, percebi que meu pequeno VPS estava ficando sem disco .

No tipo shell / prompt (Linux / Unix)

df -h

para ver o disco livre na sua máquina. Se você está ficando sem disco, isso pode ser o problema / problema.

    
por 23.01.2013 / 18:36
3

Outra ferramenta útil que ajudará nessa situação é nmon.

Inclui uma variedade de maneiras de visualizar os mesmos dados apresentados pelas outras ferramentas, em um pequeno pacote.

Se esse conteúdo não puder ser armazenado em cache, eu recomendaria colocar vários servidores atrás de um balanceador de carga, como haproxy no modo tcp, para distribuir a carga.

    
por 19.07.2013 / 20:17
1

Apenas para acrescentar a isso, algumas ferramentas específicas do Solaris que não foram mencionadas e que são úteis na depuração de tais problemas são "intrstat", "mpstat" e "lockstat". Tendo experimentado um problema semelhante antes em um host executando algumas cargas pesadas de ETL, o mpstat revelou uma grande quantidade de interrupções lidando com muitas E / S que sugeriam o problema.

Na época, em um T4-4 com mpstat, víamos os handups excedendo 30000 interrupções durante um curto ciclo de monitoramento, após o qual o desempenho começou a sofrer. Neste caso, a única solução foi lançar mais CPU no entanto, o trabalho foi posteriormente realizado para melhorar o código.

Brendan Gregg escreveu muito sobre performance, particularmente sobre I / O ao longo dos anos e vale a pena uma pesquisa se você quiser saber mais.

    
por 23.06.2016 / 16:20