Asterisco - muito alto Load Average sem razão

3

Há um problema com o servidor Asterisk mostrando alta carga média eu não consigo explicar. A configuração de Ny é:

  1. Asterisk 13.1.0
  2. Linux 3.13.0-24 (servidor Ubuntu)
  3. Servidor de soquete duplo (Xeon E5-2620), habilitado para HT - total de 24 núcleos; 32G RAM

O asterisco é usado para enviar mensagens de voz. Eu tenho um provedor SIP upstream, sem cartões de telefonia de hardware. Há apenas alaw / ulaw permitido no sip.conf.

Eu uso o comando AMI Originate para iniciar uma chamada; então eu executo Playback () no contexto para envio de mensagem de voz pré-gravada (arquivos ulaw no ext4 FS local). Não há outra interação com o receptor, nenhum menu IVR, nenhuma gravação de chamada. Alguns scripts muito simples do Perl AGI salvam o resultado da chamada para os DBs (MySQL e MSSQL (via Perl Sybase)); geralmente há 1-2 chamadas AGI por originar. Além disso, quase não há processamento em extensão - literalmente 20 linhas de veri fi cadores de pré-configuração para CDR () e um par de chamadas AGI. Há apenas uma conexão AMI que uso para iniciar todas as chamadas.

O específico é - a maioria das chamadas não é respondida. Eu inicio até 50 chamadas por segundo, mas apenas 5-10 são efetivamente captadas e ouvidas.

O problema é - eu tenho muito baixo uso de CPU%, mas muito alto LA. Se eu tentar 20-25 cps - 20-24 LA, mas se eu tentar aumentar para 50cps, o LA subirá para 90+. Depois de ~ 50LA, há problemas com a qualidade de áudio (e eu posso entender o porquê).

A maioria dos usuários do Asterisk afirma ter muito mais volume de chamadas com hardware menos potente.

# uptime
 12:56:36 up 9 days, 15:52,  1 user,  load average: 32,10, 33,45, 33,10

#vmstat -w 1
procs ---------------memory-------------- ---swap-- -----io---- -system-- ------cpu-----
 r  b     swpd     free     buff    cache   si   so    bi    bo   in   cs us sy id wa st
 3  0        0 30322760   199176   832452    0    0     0     0 237471 38738  5  8 87  0  0
 3  0        0 30319148   199176   832500    0    0     0     0 188340 38960  4  6 90  0  0
 3  0        0 30325528   199176   832564    0    0     0    26 319903 43916  6 10 83  0  0
105  0        0 30270288   199176   832568    0    0     0    14 175216 39014  4  6 90  0  0
16  0        0 30307908   199176   832572    0    0     0     0 323598 43428 11 12 77  0  0

# mpstat 1
Linux 3.13.0-24-generic (asterisk2)         25.02.2015      _x86_64_        (24 CPU)
13:18:09     CPU    %usr   %nice    %sys %iowait    %irq   %soft  %steal  %guest  %gnice   %idle
13:18:10     all    5,77    0,00    7,90    0,00    0,17    0,00    0,00    0,00    0,00   86,16
13:18:11     all    5,56    0,00    8,83    0,00    0,21    0,00    0,00    0,00    0,00   85,40
13:18:12     all   10,29    0,00   11,42    0,00    0,25    0,00    0,00    0,00    0,00   78,03
13:18:13     all    9,70    0,00   10,75    0,00    0,21    0,00    0,00    0,00    0,00   79,34

# uname -a
Linux asterisk2 3.13.0-24-generic #46-Ubuntu SMP Thu Apr 10 19:11:08 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

# cat /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 6
model           : 45
model name      : Intel(R) Xeon(R) CPU E5-2620 0 @ 2.00GHz
stepping        : 7
microcode       : 0x70d
cpu MHz         : 2000.216
cache size      : 15360 KB
physical id     : 0
siblings        : 12
core id         : 0
cpu cores       : 6
apicid          : 0
initial apicid  : 0
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx lahf_lm arat epb xsaveopt pln pts dtherm tpr_shadow vnmi flexpriority ept vpid
bogomips        : 4000.43
clflush size    : 64
cache_alignment : 64
address sizes   : 46 bits physical, 48 bits virtual

...

processor       : 23
vendor_id       : GenuineIntel
cpu family      : 6
model           : 45
model name      : Intel(R) Xeon(R) CPU E5-2620 0 @ 2.00GHz
stepping        : 7
microcode       : 0x70d
cpu MHz         : 2000.216
cache size      : 15360 KB
physical id     : 1
siblings        : 12
core id         : 5
cpu cores       : 6
apicid          : 43
initial apicid  : 43
fpu             : yes
fpu_exception   : yes
cpuid level     : 13
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx lahf_lm arat epb xsaveopt pln pts dtherm tpr_shadow vnmi flexpriority ept vpid
bogomips        : 4001.85
clflush size    : 64
cache_alignment : 64
address sizes   : 46 bits physical, 48 bits virtual

# cat /proc/interrupts
            CPU02      CPU23
   0:         24          0  IR-IO-APIC-edge      timer
   8:          1          0  IR-IO-APIC-edge      rtc0
   9:          2          0  IR-IO-APIC-fasteoi   acpi
  16:         33          0  IR-IO-APIC-fasteoi   ehci_hcd:usb1
  23:        107          0  IR-IO-APIC-fasteoi   ehci_hcd:usb2
  88:          0          0  DMAR_MSI-edge      dmar0
  89:          0          0  DMAR_MSI-edge      dmar1
  90:    1855369          0  IR-PCI-MSI-edge      ahci
  91:          1          0  IR-PCI-MSI-edge      eth0
  92:      11296          0  IR-PCI-MSI-edge      eth0-TxRx-0
  93:        790          0  IR-PCI-MSI-edge      eth0-TxRx-1
  94:   85066770          0  IR-PCI-MSI-edge      eth0-TxRx-2
  95:       6851          0  IR-PCI-MSI-edge      eth0-TxRx-3
  96:     174614          0  IR-PCI-MSI-edge      eth0-TxRx-4
  97:    4846139          0  IR-PCI-MSI-edge      eth0-TxRx-5
  98:     136593          0  IR-PCI-MSI-edge      eth0-TxRx-6
  99:    1294090          0  IR-PCI-MSI-edge      eth0-TxRx-7
 109:          2          0  IR-PCI-MSI-edge      ioat-msix
 110:          2          0  IR-PCI-MSI-edge      ioat-msix
 111:          2          0  IR-PCI-MSI-edge      ioat-msix
 112:          2          0  IR-PCI-MSI-edge      ioat-msix
 113:          2          0  IR-PCI-MSI-edge      ioat-msix
 114:          2          0  IR-PCI-MSI-edge      ioat-msix
 115:          2          0  IR-PCI-MSI-edge      ioat-msix
 116:          2          0  IR-PCI-MSI-edge      ioat-msix
 117:          0          0  IR-PCI-MSI-edge      ioat-msix
 118:          0          0  IR-PCI-MSI-edge      ioat-msix
 119:          0          0  IR-PCI-MSI-edge      ioat-msix
 120:          0          0  IR-PCI-MSI-edge      ioat-msix
 121:          0          0  IR-PCI-MSI-edge      ioat-msix
 122:          0          0  IR-PCI-MSI-edge      ioat-msix
 123:          0          0  IR-PCI-MSI-edge      ioat-msix
 124:          0          0  IR-PCI-MSI-edge      ioat-msix
 NMI:       3642       1990   Non-maskable interrupts
 LOC:   53207172   19108700   Local timer interrupts
 SPU:          0          0   Spurious interrupts
 PMI:       3642       1990   Performance monitoring interrupts
 IWI:     804483      60489   IRQ work interrupts
 RTR:          0          0   APIC ICR read retries
 RES:   60096784   31495629   Rescheduling interrupts
 CAL: 4046461325 4101338127   Function call interrupts
 TLB: 2390847639 1479027286   TLB shootdowns
 TRM:          0          0   Thermal event interrupts
 THR:          0          0   Threshold APIC interrupts
 MCE:          0          0   Machine check exceptions
 MCP:       2501       2501   Machine check polls
 ERR:          0
 MIS:          0

# atop
CPL | avg1   22.45 |  avg5   22.65 |              |  avg15  22.74 |              |  csw   379728 | intr 1612164 |               |              |  numcpu    24 |
MEM | tot    31.4G |  free   28.4G | cache 829.3M |  dirty   0.0M | buff  194.7M |  slab  188.0M |              |               |              |               |
SWP | tot    32.0G |  free   32.0G |              |               |              |               |              |               | vmcom 737.1M |  vmlim  47.7G |
MDD |          md0 |  busy      0% | read       0 |  write     12 | KiB/r      0 |  KiB/w      4 | MBr/s   0.00 |  MBw/s   0.01 | avq     0.00 |  avio 0.00 ms |
DSK |          sda |  busy      1% | read       0 |  write     11 | KiB/r      0 |  KiB/w      5 | MBr/s   0.00 |  MBw/s   0.01 | avq     1.00 |  avio 12.7 ms |
DSK |          sdb |  busy      1% | read       0 |  write     11 | KiB/r      0 |  KiB/w      5 | MBr/s   0.00 |  MBw/s   0.01 | avq     1.00 |  avio 11.6 ms |
NET | transport    |  tcpi    1994 | tcpo    2452 |  udpi   17159 | udpo   14811 |  tcpao    117 | tcppo      1 |  tcprs      0 | tcpie      0 |  udpip      0 |
NET | network      |  ipi    19235 | ipo    17268 |  ipfrw      0 | deliv  19235 |               |              |               | icmpi      7 |  icmpo      0 |
NET | eth0      0% |  pcki   19345 | pcko   17272 |  si 3256 Kbps | so 2954 Kbps |  coll       0 | erri       0 |  erro       0 | drpi       0 |  drpo       0 |

Você pode ver que existem números muito altos nos campos cs e vmstat. Eu não posso explicá-los.

Então, até onde eu entendi - há rajadas de threads se tornando executáveis em um tempo muito curto (você pode ver uma dessas explosões na saída do vmstat). Mas o que na minha configuração pode causar tal coisa?

Eu tentei:

  1. Jogando com pacote de codecs no sip.conf (houve uma ideia de que muitos pacotes de micro foram enviados)
  2. Alterando o formato do arquivo de reprodução;
  3. Desabilitando completamente as chamadas de script AGI (comentando-as em extensions.conf);
  4. Alterando o modo de usar o canal AMI (alterando intervalos e valores de burst para achatar a carga)

mas nada ajudou.

Eu verifiquei tudo o que posso pensar - não há nenhum disco IO, nenhum outro aplicativo neste servidor. Há caras na mailllist com problemas semelhantes, mas isso não foi resolvido, e foi há muito tempo atrás.

Mais um pensamento - Eu tenho mais um servidor com o mesmo problema com hardware muito similar e config Asterisk, mas há Asterisk 1.8 (FreePBX) e CentOS estão sendo usados. Eu suspeito, isso leva ao meu uso particular.

Talvez, este seja um problema central da AMI e eu deveria usar outra coisa para chamadas de inicialização em massa?

EDIT1: Aqui está o meu gráfico de LA:

EDIT2: Aqui está o Asterisk strace. É relativamente o mesmo em alta e baixa carga. Eu não sou um programador linux, não consigo interpretar corretamente.

# strace -f -q -c -p 17150
^C% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 42.05 1595.370429       13209    120778     18231 futex
 41.21 1563.521630     6304523       248        14 restart_syscall
 15.96  605.470340        4726    128105        26 poll
  0.23    8.811410       12037       732           nanosleep
  0.16    5.903679          26    228693     22073 read
  0.15    5.600020          66     85202           write
    
por Worldexe 26.02.2015 / 10:11

1 resposta

3

Ookay, eu percebi isso. Isso é apenas uma solução alternativa, mas o problema caiu para um nível aceitável para mim.

Após a reinicialização indesejada em meio a um dia, notei que a média de carga caiu muito! Eu verifiquei o nosso sistema de monitoramento do servidor - LA sempre subiu pouco a pouco em um 3-4 horas de carga contínua (e estável). Isso não foi notado, porque eu não pude reinicializá-lo durante o dia anterior.

Como eu disse, tenho alguns scripts Perl, que são chamados via AGI() application. Um deles é chamado em h extension; ele apenas executa uma consulta de banco de dados simples. Descobriu-se que às vezes DB ficava um pouco sobrecarregado; as consultas têm que esperar por 200 a 500 ms; O asterisco tem que esperar até que o script Perl termine.

Então, eu enterrei em fork() meu script Perl no início - fazendo a chamada AGI () retornar sempre imediatamente. Isso ajudou muito! LA ficou muito estável. Esta não é uma solução completa - parece algo que ainda está corrompendo no interior do Asterisk, mas muito mais lento, isso quase não é um problema.

Para aqueles que procuram código pronto para uso (não se esqueça de obter todas as variáveis antes de fork() ing, pois você não poderá acessar $AGI depois):

my $AGI = new Asterisk::AGI;

# get all your variables here
my $var = $AGI->get_variable('var');

undef $AGI;

if (fork) { exit 0; };
open STDIN,  '<', '/dev/null'; # dont forget to free your parent's file handles
open STDOUT, '>', '/dev/null';
open STDERR, '>&STDOUT';

Parece um erro - mas eu me pergunto por que não há pessoas com esse tipo de problema além de mim.

EDIT1: Bem, o problema desapareceu completamente depois de eliminar as chamadas AGI . Eu simplesmente fiz algumas funções ODBC ( func_odbc.conf ) personalizadas, que apenas salvam informações para processamento assíncrono (processado posteriormente por daemon perl separado). LA caiu de 20-25 para 0.5-0.9 (!). Eu nunca pensei que AGI pudesse causar uma carga tão grande.

    
por 11.03.2015 / 22:27