Como depurar tempos limite do apache?

13

Eu executo um aplicativo Web PHP em um servidor Apache 2.2 (Ubuntu Server 10.04, 8x2GHz, 12Gb RAM) usando prefork. Todos os dias o Apache recebe cerca de 100k-200k solicitações, destas cerca de 100-200 atingem o limite de tempo limite (aproximadamente uma em cada mil), praticamente todas as outras solicitações são atendidas bem abaixo do tempo limite.

O que posso fazer para descobrir por que isso acontece? Ou é normal que algumas partes pequenas de todos os pedidos expirem?

Isto é o que eu fiz até agora:

Solicita tempo de resposta

Como pode ser visto, há muito poucas solicitações entre o limite de tempo limite e uma solicitação mais razoável. Atualmente, o limite de tempo limite é definido como 50 segundos, anteriormente era definido como 300 e ainda era a mesma situação com alguns tempos limite e, em seguida, uma enorme lacuna nas demais solicitações.

Todas as solicitações que expiram são AJAXsolicitações, mas a grande maioria delas é, então talvez isso seja mais uma coincidência. O código de retorno do Apache é 200, mas o limite de tempo limite é claramente atingido. Eles são de uma ampla variedade de IPs diferentes.

Examinei os pedidos que atingiram o tempo limite e não há nada de especial neles, se eu fizer os mesmos pedidos que eles passam em muito menos de um segundo.

Eu tentei olhar para os diferentes recursos para ver se consigo encontrar a causa, mas sem sorte. Sempre há muita memória livre (o mínimo é cerca de 3 GB livres), a carga às vezes chega a 1,4 e a utilização da CPU é de 40%, mas muitos dos tempos limite ocorrem quando a carga e a utilização da CPU são baixas. Gravação / leitura de disco são praticamente constantes durante o dia. Não há entradas no log de consultas lentas do MySQL (configurado para registrar algo acima de 1 segundo), uma solicitação não usa tantas gravações / leituras de banco de dados.

Solicitar tempo de resposta com carregamento do sistema / CPU

Azul é a utilização da CPU, cujo pico é de 40%, o marrom é carregado com o pico de 1,4. Para que possamos ver o tempo limite, mesmo com baixa utilização / carga da CPU (os picos de dez segundos correspondem bem à utilização da CPU, mas esse é outro problema, tenho maiores esperanças de descobrir o que pode estar causando isso).

Não há erros no log de erros do Apache e não o vi atingir mais de 200 processos ativos do Apache.

Configurações do servidor:

Timeout 50 
KeepAlive On
MaxKeepAliveRequests 100
KeepAliveTimeout 2

<IfModule mpm_prefork_module>
    ServerLimit     350
    StartServers        20
    MinSpareServers     75
    MaxSpareServers     150
    MaxClients          320
    MaxRequestsPerChild 5000
</IfModule>

Atualizar:

Atualizei para o Ubuntu 12.04.1, por precaução, sem alterações. Adicionei mod_reqtimeout com as configurações:

RequestReadTimeout header=20-40,minrate=500
RequestReadTimeout body=10,minrate=500

Agora, quase todos os tempos limite acontecem em 10 segundos, um ou dois em 20 segundos. Entendo que isso significa que na maioria das vezes ele está recebendo o corpo da solicitação que é problemático para receber? O corpo da solicitação nunca deve ser maior que algumas centenas de bytes. Eu monitorei o tráfego de rede por 1 segundo e ele nunca ultrapassa 1Mbit / s e não vejo rxerrs ou rxdorps, considerando que o servidor está em uma linha de 1Gbit / s não soa como o HopelessN00b postou sobre. Poderia ser apenas um caso de algumas conexões ruins do usuário?

Para os picos a cada hora (eles parecem se desviar um pouco, nos gráficos acima, eles estão em 33 minutos e agora em 12 minutos), tentei verificar se há algo em execução periodicamente ( crons etc) mas não encontrou nada. A coleta de lixo do PHP é executada duas vezes a cada hora, mas não no momento dos picos, ainda tentei desativá-lo, mas não faz diferença.

Eu usei o dstat com --top-cpu e top para analisar os processos no momento dos picos e tudo o que aparece é o apache trabalhando duro por alguns segundos, mas nenhum outro processo está usando uma CPU significativa.

Fiz um gráfico ampliado dos picos: Tempo de resposta de solicitação ampliada

Para mim, parece que o apache pára por alguns segundos e depois trabalha duro para processar os pedidos que chegaram durante a parada. O que pode causar essa interrupção ou estou interpretando mal?

Leon
fonte
1
Eu queria publicar alguns gráficos sobre as solicitações, mas meu representante é muito baixo.
Leon

Respostas:

4

A primeira coisa que observo, olhando para o seu primeiro gráfico, parece haver uma desaceleração horária (ocorrendo cerca de 40 minutos após a hora) que pode estar contribuindo para o problema. Você deve dar uma olhada nos agendadores de tarefas no sistema operacional / banco de dados.

Com base nos dados que você forneceu, minha próxima etapa seria verificar a frequência dos tempos de resposta (número de respostas no eixo Y versus duração no X), mas incluindo apenas URLs que exibem o tempo limite (ou preferencialmente um URL por vez) ) Em um sistema típico, isso deve seguir uma distribuição normal ou poisson - os pedidos que estão atingindo o tempo limite podem simplesmente fazer parte da cauda - nesse caso, você precisa concentrar seus esforços no ajuste geral. OTOH, se a distribuição for bimodal, você precisará procurar contenção em algum lugar do seu código.

symcbean
fonte
Obrigado pela sua resposta. Estou analisando o que pode estar causando as desacelerações por hora. Nesse meio tempo, fiz um gráfico de frequência dos dados que já tenho. Este é apenas um dos URLs com um problema de tempo limite (mas os outros se parecem muito): leela.kikora.no/apache_hist_show.png A quantidade de tempos limite é muito pequena se comparada àquela que leva menos de 10 segundos, mas parece como se não fosse parte da cauda. Mas, por outro lado, pode ser que, já que representam algo que levaria mais de 50 segundos, deveria parecer com isso.
Leon
3

Tenho outra idéia sobre isso, com base no fato de você receber um grande número de solicitações por dia e parecer ter tempos limite apenas durante o horário de pico (das fotos que você postou).

Há uma postagem no blog Server Fault,Per Second Measurements Don't Cut It ... é possível que algumas dessas solicitações estejam com o mesmo problema que a equipe ServerFault encontrou?

Descobrimos que estávamos descartando pacotes com bastante frequência em interfaces de 1 Gbit / s a ​​taxas de apenas 10 a 30 MBit / s, o que prejudica nosso desempenho. Isso ocorre porque essa taxa de 10 a 30 MBit / s é realmente o número de bits transferidos a cada 5 minutos convertidos em uma taxa de um segundo. Quando nos aproximamos do Wireshark e usamos gráficos de milissegundos IO, vimos que frequentemente estourávamos a taxa de 1 Mbit por milissegundo das chamadas interfaces de 1 Gbit / s.

HopelessN00b
fonte
Interessante, vou dar uma olhada. Eu habilitei o mod_reqtimeout e o configurei como RequestReadTimeout header = 20-40, minrate = 500 e RequestReadTimeout body = 10, minrate = 500 e quase todos os tempos limite ocorrem agora em 10 segundos. Entendo que isso significa que o corpo da solicitação leva muito tempo (o corpo nunca deve ter mais do que algumas centenas de bytes), para que alguns dos meus usuários tenham conexões ruins ou, como você diz, há algum congestionamento no lado do servidor.
Leon