Eu tenho um script que reporta o uso de cpu de um programa específico lendo valores de pidstat. O script é iniciado como:
pidstat -C ^frontend$ -h -l -p ALL 1 1
Os valores relatados dessa forma, às vezes, excedem 100% do uso da CPU, o que não é possível, já que o processo tem um único corte.
Depois de subir e descer tentando encontrar o que poderia estar causando esse comportamento, tentei simplesmente aumentar o tempo que o pidstat coletaria informações e descobri que, surpreendentemente, os valores tendem a ser muito mais razoáveis:
pidstat -C ^frontend$ -h -l -p ALL 1 10
Linux 3.13.0-32-generic (eu-123) 09/22/2014 _x86_64_ (8 CPU)
# Time PID %usr %system %guest %CPU CPU Command
1411396853 15884 28.43 29.41 0.00 57.84 1 /srv/propulsor/frontend-01/frontend
1411396853 15911 33.33 32.35 0.00 65.69 2 /srv/propulsor/frontend-02/frontend
1411396853 15968 58.82 0.00 0.00 58.82 3 /srv/propulsor/frontend-03/frontend
# Time PID %usr %system %guest %CPU CPU Command
1411396854 15884 141.00 4.00 0.00 145.00 1 /srv/propulsor/frontend-01/frontend
1411396854 15911 143.00 5.00 0.00 148.00 2 /srv/propulsor/frontend-02/frontend
1411396854 15968 32.00 13.00 0.00 45.00 3 /srv/propulsor/frontend-03/frontend
# Time PID %usr %system %guest %CPU CPU Command
1411396855 15884 0.00 0.00 0.00 0.00 1 /srv/propulsor/frontend-01/frontend
1411396855 15911 0.00 0.00 0.00 0.00 2 /srv/propulsor/frontend-02/frontend
1411396855 15968 32.00 32.00 0.00 64.00 3 /srv/propulsor/frontend-03/frontend
# Time PID %usr %system %guest %CPU CPU Command
1411396856 15884 61.00 0.00 0.00 61.00 1 /srv/propulsor/frontend-01/frontend
1411396856 15911 69.00 0.00 0.00 69.00 2 /srv/propulsor/frontend-02/frontend
1411396856 15968 33.00 31.00 0.00 64.00 3 /srv/propulsor/frontend-03/frontend
# Time PID %usr %system %guest %CPU CPU Command
1411396857 15884 30.00 7.00 0.00 37.00 1 /srv/propulsor/frontend-01/frontend
1411396857 15911 34.00 20.00 0.00 54.00 2 /srv/propulsor/frontend-02/frontend
1411396857 15968 32.00 32.00 0.00 64.00 3 /srv/propulsor/frontend-03/frontend
# Time PID %usr %system %guest %CPU CPU Command
1411396858 15884 31.00 32.00 0.00 63.00 1 /srv/propulsor/frontend-01/frontend
1411396858 15911 34.00 33.00 0.00 67.00 2 /srv/propulsor/frontend-02/frontend
1411396858 15968 141.00 7.00 0.00 148.00 3 /srv/propulsor/frontend-03/frontend
[snip]
Em comparação com:
root@eu-123 ~ # pidstat -C ^frontend$ -h -l -p ALL 3 10
Linux 3.13.0-32-generic (eu-123) 09/22/2014 _x86_64_ (8 CPU)
# Time PID %usr %system %guest %CPU CPU Command
1411397159 15884 37.09 10.60 0.00 47.68 1 /srv/propulsor/frontend-01/frontend
1411397159 15911 30.46 29.80 0.00 60.26 2 /srv/propulsor/frontend-02/frontend
1411397159 15968 60.60 13.25 0.00 73.84 3 /srv/propulsor/frontend-03/frontend
# Time PID %usr %system %guest %CPU CPU Command
1411397162 15884 29.33 29.33 0.00 58.67 1 /srv/propulsor/frontend-01/frontend
1411397162 15911 66.00 2.00 0.00 68.00 2 /srv/propulsor/frontend-02/frontend
1411397162 15968 41.00 15.00 0.00 56.00 3 /srv/propulsor/frontend-03/frontend
# Time PID %usr %system %guest %CPU CPU Command
1411397165 15884 66.33 0.00 0.00 66.33 1 /srv/propulsor/frontend-01/frontend
1411397165 15911 30.00 19.67 0.00 49.67 2 /srv/propulsor/frontend-02/frontend
1411397165 15968 61.00 13.33 0.00 74.33 3 /srv/propulsor/frontend-03/frontend
# Time PID %usr %system %guest %CPU CPU Command
1411397168 15884 30.00 23.33 0.00 53.33 1 /srv/propulsor/frontend-01/frontend
1411397168 15911 66.00 21.33 0.00 87.33 2 /srv/propulsor/frontend-02/frontend
1411397168 15968 42.00 15.67 0.00 57.67 3 /srv/propulsor/frontend-03/frontend
# Time PID %usr %system %guest %CPU CPU Command
1411397171 15884 59.00 12.33 0.00 71.33 1 /srv/propulsor/frontend-01/frontend
1411397171 15911 30.00 0.67 0.00 30.67 2 /srv/propulsor/frontend-02/frontend
1411397171 15968 70.00 24.67 0.00 94.67 3 /srv/propulsor/frontend-03/frontend
# Time PID %usr %system %guest %CPU CPU Command
1411397174 15884 37.67 11.00 0.00 48.67 1 /srv/propulsor/frontend-01/frontend
1411397174 15911 30.00 29.67 0.00 59.67 2 /srv/propulsor/frontend-02/frontend
1411397174 15968 33.00 4.67 0.00 37.67 3 /srv/propulsor/frontend-03/frontend
# Time PID %usr %system %guest %CPU CPU Command
1411397177 15884 65.33 21.67 0.00 87.00 1 /srv/propulsor/frontend-01/frontend
1411397177 15911 65.67 2.33 0.00 68.00 2 /srv/propulsor/frontend-02/frontend
1411397177 15968 32.33 32.00 0.00 64.33 3 /srv/propulsor/frontend-03/frontend
# Time PID %usr %system %guest %CPU CPU Command
1411397180 15884 29.00 0.00 0.00 29.00 1 /srv/propulsor/frontend-01/frontend
1411397180 15911 30.00 19.33 0.00 49.33 2 /srv/propulsor/frontend-02/frontend
1411397180 15968 70.00 2.33 0.00 72.33 3 /srv/propulsor/frontend-03/frontend
[snip]
Ok, agora a leitura parece mais razoável, mas a pergunta para mim continua: o que está causando essa diferença? E como pode o pidstat 1 1 retornar valores acima de 100%?
Pergunta de bônus: devo usar apenas ferramentas diferentes para rastrear o uso da CPU de meus processos?
Obrigado antecipadamente
Editar: Continuei pesquisando o assunto. Parece que o processo só começa a fazer uma coisa tão estranha depois de um tempo (ou seja, ~ 2 semanas de vida). Ao mesmo tempo, encontramos uma quantidade maior de conexões gerenciadas pelo processo.
O comportamento observado é obter algumas execuções de pidstat com um uso de cpu de 0%, seguido de um pico alto, cuja média na magnitude de décimos permanece dentro dos valores de uso de cpu esperados.
Estou começando a pensar que poderia ser algo como o aplicativo está fazendo um loop de chamadas do sistema através do pool de conexão que depois de um tempo é grande o suficiente para que ele não anote suas /proc/ stats fazendo pidstat acreditar que o uso é de 0% e, portanto, atinge um grande > 100% de uso após algumas rodadas em 0.
Quando o processo escreve os /proc/ data? Tanto quanto eu entendo, pidstat usa essa informação para calcular o uso da CPU, ou estou errado?
Espero que alguém possa esclarecer esta questão ...