Alta% sy na saída superior, como depurar?

Question

Temos dois servidores configurados de forma idêntica e um deles mostra um alto %sy , enquanto o outro não. Isso parece indicar que o sistema está ocupado fazendo alguma coisa.

Cpu(s): 28.1%us, 66.3%sy,  0.7%ni,  4.8%id,  0.0%wa,  0.2%hi,  0.0%si,  0.0%st

Minha pergunta

Como eu determino quais sub-módulos do kernel estão causando essa carga alta?

Informações adicionais

• Ambos os sistemas são Ubuntu 12.04 LTS
• Ambos os sistemas são instâncias do EC2 em execução no AWS (Amazon)

O sistema afetado experimentou o que parece ser um rastreamento de pilha nos logs, junto com esta mensagem:

mensagem de bloqueio suave

[33644527.529071] BUG: soft lockup - CPU#0 stuck for 23s! [monitorcron:31103]
[33644527.529087] Modules linked in: isofs ip6table_filter ip6_tables ipt_REJECT xt_state iptable_filter xt_REDIRECT xt_comment xt_multiport iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack ip_tables x_tables intel_rapl x86_pkg_temp_thermal coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel ablk_helper cryptd lrw gf128mul glue_helper aes_x86_64

Stack trace

[33644527.529116] CPU: 0 PID: 31103 Comm: moncron Tainted: G        W    3.13.0-34-generic #60~precise1-Ubuntu
[33644527.529120] task: ffff8800a565afe0 ti: ffff8800c6150000 task.ti: ffff8800c6150000
[33644527.529122] RIP: e030:[<ffffffff8175f32f>]  [<ffffffff8175f32f>] _raw_spin_unlock+0x1f/0x30
[33644527.529133] RSP: e02b:ffff8800c6151c58  EFLAGS: 00000286
[33644527.529135] RAX: ffff8801aed728c0 RBX: ffff8800c6151cc0 RCX: ffff8801aed728c0
[33644527.529137] RDX: ffff8801aed728c0 RSI: 00000000a10ca10a RDI: ffff8801aed72898
[33644527.529139] RBP: ffff8800c6151c58 R08: 000000000000000a R09: 0000000000000000
[33644527.529141] R10: 0000000000000131 R11: 0000000000000130 R12: ffff8801aed72840
[33644527.529142] R13: ffff8801aed728c0 R14: ffff8801aed72898 R15: ffff8801aed72840
[33644527.529149] FS:  00007f37888a8700(0000) GS:ffff8801dee00000(0000) knlGS:0000000000000000
[33644527.529152] CS:  e033 DS: 0000 ES: 0000 CR0: 000000008005003b
[33644527.529153] CR2: 0000000000dac3b8 CR3: 00000000051e5000 CR4: 0000000000002660
[33644527.529156] Stack:
[33644527.529158]  ffff8800c6151ca8 ffffffff811e0a98 ffff8800c6151cb8 ffff8801aed728c0
[33644527.529161]  ffff8800c6151d00 ffff8800c6151cc0 ffff8801aee64900 0000000000007980
[33644527.529164]  0000000000007980 ffff8801aee64900 ffff8800c6151ce8 ffffffff811e0c18
[33644527.529168] Call Trace:
[33644527.529177]  [<ffffffff811e0a98>] shrink_dentry_list+0x28/0xe0
[33644527.529181]  [<ffffffff811e0c18>] shrink_dcache_parent+0x28/0x70
[33644527.529188]  [<ffffffff81232257>] proc_flush_task_mnt.isra.15+0x77/0x170
[33644527.529194]  [<ffffffff81235776>] proc_flush_task+0x56/0x70
[33644527.529200]  [<ffffffff8106c803>] release_task+0x33/0x130
[33644527.529204]  [<ffffffff8106cdcf>] wait_task_zombie+0x4cf/0x5f0
[33644527.529209]  [<ffffffff8106cffb>] wait_consider_task.part.8+0x10b/0x180
[33644527.529213]  [<ffffffff8106d0d5>] wait_consider_task+0x65/0x70
[33644527.529217]  [<ffffffff8106d1e1>] do_wait+0x101/0x260
[33644527.529220]  [<ffffffff8106e213>] SyS_wait4+0xa3/0x100
[33644527.529225]  [<ffffffff8106bc10>] ? task_stopped_code+0x50/0x50
[33644527.529231]  [<ffffffff8176853f>] tracesys+0xe1/0xe6
[33644527.529232] Code: 66 66 66 2e 0f 1f 84 00 00 00 00 00 66 66 66 66 90 55 48 89 e5 e9 0a 00 00 00 66 83 07 02 5d c3 0f 1f 40 00 8b 37 f0 66 83 07 02 <f6> 47 02 01 74 ed e8 d0 74 fe ff 5d c3 0f 1f 40 00 66 66 66 66 

Estou assumindo que isso está relacionado, mas não determinou como ou por que, se é que realmente é.

    

Answer 1

Primeiro, você deve tentar determinar se esse problema é causado por um único processo / aplicativo ou por todo o sistema. Existem provavelmente ferramentas (das quais eu não estou ciente) para fazer isto de uma forma mais direta, mas sem elas eu sugiro iterar através de todos os processos que consomem uma parte relevante do tempo da CPU e parem por um momento ( kill -STOP $PID ). Se isso é causado por um ou poucos processos, o valor %sy deve cair muito.

Se você encontrou tal processo, então você pode anexar strace -c -p $PID a ele por alguns segundos para ver quais syscalls são usados e por quanto tempo. Isso pode lhe dar uma dica de quais partes do kernel estão envolvidas (especialmente se você compará-lo com a saída no outro sistema).