Tempo de execução do comando lento no Linux

Question

Em caras superusuários sugeriram que eu fosse até aqui.

Nós experimentamos algum tempo de execução de comando simples e lento no Linux, possivelmente relacionado à lentidão do procfs.

Como o comando uptime simples pode demorar alguns segundos para ser executado.

Aqui estão as entradas:

• Plataforma: AWS
• Instância: x1.32xl (128 núcleos com 2T RAM)
• SO: Ubuntu 16.04
• Kernel: 4.4.0-1043-aws

Executamos o docker com cerca de 250 contêineres.

• Versão do Docker: 17.09-ce

Utilização:

• utilização da CPU: < 50%
• Utilização da mem: <50%

Algumas estatísticas do sistema operacional:

# cat /proc/loadavg
100.45 108.30 109.41 35/254951 544357

# vmstat 1 3
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
110  2 791584 485552640 50354496 687472448    0    0   426   183    1    1 10  8 82  1  0
13  0 791584 485495104 50353940 687477568    0    0 22820 47984 196555 326943 12 12 75  1  0
33  1 791584 485385632 50352428 687473536    0    0 38932 52892 166486 389428 13 14 72  1  0

# ps axu| wc -l
3792

O que exatamente acontece?

O lançamento de comandos simples leva tempo, quando os comandos usam procfs de alguma forma. Como fazer ls em um diretório com alguns arquivos fica preso no syscall aberto do procfs

# strace -r ls
...
0.000084 open("/proc/filesystems", O_RDONLY) = 3
3.652504 fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
...

Ou uptime :

# strace -r uptime
...
0.000035 open("/proc/filesystems", O_RDONLY) = 3
11.014154 fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
...
0.000044 open("/proc/uptime", O_RDONLY) = 3
1.554646 lseek(3, 0, SEEK_SET)
...

Quick Q / A e o que já tentamos:

• Esta lentidão só está presente no nível do host. Em contêineres, não vemos esses problemas. Brincamos um pouco e vemos esse problema quando executamos o contêiner com ambos --ipc=host e --pid=host flags.
• Rastreamos essa lentidão em procfs para mutex_lock aqui link
• Muitos contêineres
  • Não, temos 600 em outro host e tudo de bom
• Muitos processos
  • Não, temos 10K em outro host e tudo de bom
• Muitos tópicos
  • Isso pode ser. Nós não temos essa quantidade de threads em nenhum outro host, mas tentamos reproduzi-lo em uma instância x1.32xlarge limpa e falhamos. Por isso, pode ser mais um passo.

Todas as ideias e sugestões são bem-vindas.

    

Answer 1

Encontramos a causa raiz.

Nós corremos

/usr/share/bcc/tools/funcslower -m 250 -T proc_pid_readdir

para obter processos que estavam causando chamadas longas para proc_pid_readdir

Quando fizemos isso, conseguimos alguns processos:

zabbix_agent
atop
byobu

Todos estes estavam fazendo chamadas muito longas.

TIME       COMM           PID    LAT(ms)             RVAL FUNC
20:01:35   zabbix_agentd  921144 1258.01                0 proc_pid_readdir 
20:01:38   zabbix_agentd  921144 2692.71                0 proc_pid_readdir 
20:01:39   zabbix_agentd  921145 1276.88                0 proc_pid_readdir

Quando paramos TODOS estes - vimos uma grande melhoria.

Então parece que misturar muitos processos e threads + chamar proc_pid_readdir com muita freqüência causa lentidão no procfs.

Vamos testar hoje o kernel 4.14 e ver se melhora.

ATUALIZAÇÃO:

O Kernel 4.14 resolveu nosso problema também. Mutex simples para cada inode é substituído agora por rwsem .