アスタリスク - 理由もなく非常に高い負荷平均

アスタリスク - 理由もなく非常に高い負荷平均

Asterisk サーバーに高い負荷平均が表示されるという問題がありますが、説明できません。Ny の設定は次のとおりです。

  1. アスタリスク 13.1.0
  2. Linux 3.13.0-24 (Ubuntu サーバー)
  3. デュアルソケット (Xeon E5-2620) サーバー、HT 対応 - 合計 24 コア、32G RAM

Asterisk は音声メッセージの送信に使用されます。アップストリーム SIP プロバイダーは 1 つあり、ハードウェア テレフォニー カードはありません。sip.conf で許可されるのは alaw/ulaw のみです。

通話を開始するために AMI Originate コマンドを使用します。次に、録音済みの音声メッセージ (ローカル ext4 FS の ulaw ファイル) を送信するためにコンテキストで Playback() を実行します。着信側とのその他のやり取りはなく、IVR メニューや通話録音もありません。いくつかの非常にシンプルな Perl AGI スクリプトが通話結果を DB (MySQL および MSSQL (Perl Sybase 経由)) に保存します。通常、Originate ごとに 1 ~ 2 回の AGI 呼び出しがあります。また、拡張機能での処理はほとんどなく、文字通り CDR() 用の事前設定変数が 20 行と、いくつかの AGI 呼び出しがあります。すべての通話を開始するために使用する AMI 接続は 1 つだけです。

具体的には、ほとんどの通話は応答されません。1 秒あたり最大 50 件の通話を発信しますが、実際に応答され、聞かれるのは 5 ~ 10 件だけです。

問題は、CPU 使用率は非常に低いのに、LA が非常に高いことです。20~25 cps、20~24 LA で開始し、50cps まで上げようとすると、LA は 90 以上に上昇します。約 50LA を超えると、オーディオ品質に問題が発生します (その理由は理解できます)。

ほとんどの Asterisk ユーザーは、それほど強力でないハードウェアでも通話量がはるかに多いと主張しています。

# 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 |

ご覧のとおり、cs および vmstat フィールドに非常に高い数値があります。説明できません。

つまり、私が理解している限りでは、非常に短い時間でスレッドがバーストして実行可能になるということです (vmstat の出力でそのようなバーストの 1 つを確認できます)。しかし、私の設定の何がそのようなことを引き起こすのでしょうか?

私は試した:

  1. sip.conf でコーデックのパケット化を試しています (送信されるマイクロパケットが多すぎるのではないかという考えがありました);
  2. 再生ファイル形式の変更;
  3. AGI スクリプト呼び出しを完全に無効にする (extensions.conf でコメントアウトする)。
  4. AMI チャネルの使用方法を変更する (負荷を平準化するために間隔とバースト量を変更する)

しかし何も役に立ちませんでした。

考えられる限りすべてチェックしました。ディスク IO はなく、このサーバーには他のアプリもありません。mailllist に同様の問題を抱えている人がいますが、解決されておらず、かなり前のことです。

もう 1 つ考えたのは、非常によく似たハードウェアと Asterisk 構成で同じ問題を抱えているサーバーがもう 1 台あるのですが、そこでは Asterisk 1.8 (FreePBX) と CentOS が使用されているということです。これが私の特定の使用法につながっているのではないかと思います。

おそらく、これは AMI の根本的な問題であり、大量の初期化呼び出しには何か他のものを使用する必要がありますか?

編集1: これが私の LA グラフです:

ここに画像の説明を入力してください

編集2:これは Asterisk strace です。高負荷でも低負荷でもほぼ同じです。私は Linux プログラマーではないので、適切に解釈できません。

# 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

答え1

わかりました。解決しました。これは単なる回避策ですが、問題は私にとって許容できるレベルまで減少しました。

日中に予期せぬ再起動が行われた後、負荷平均が大幅に低下していることに気付きました。サーバー監視システムを確認したところ、負荷平均は 3 ~ 4 時間連続して (かつ安定して) 負荷がかかっている間、常に少しずつ上昇していました。前日中に再起動できなかったため、これは目立ちませんでした。

前述したように、アプリケーション経由で呼び出される Perl スクリプトがいくつかありますAGI()。そのうちの 1 つはh拡張機能で呼び出され、単純な DB クエリを 1 つ実行するだけです。DB が少し過負荷になることがあることが判明しました。クエリは 200 ~ 500 ミリ秒待機する必要があり、Asterisk は Perl スクリプトが終了するまで待機する必要があります。

そこで、私はfork()最初に Perl スクリプトを変更し、AGI() 呼び出しが常に即時に返されるようにしました。これは非常に役立ちました。LA は大幅に安定しました。これは完全な解決策ではありません。Asterisk の内部でまだ何かが壊れているようですが、速度は大幅に低下し、ほとんど問題にはなりません。

すぐに使えるコードを探している人向け (fork()の前にすべての変数を取得することを忘れないでください。後でアクセスできなくなります$AGI):

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';

バグのようですが、私以外にこのような問題を抱えている人がいないのはなぜでしょうか。

編集1:AGI呼び出しをなくした後、問題は完全に解消しました。私は、非同期処理の情報を保存するカスタムODBC関数 ( ) をいくつか作成しただけです (これは後で別の Perl デーモンによって処理されます)。LA は 20 ~ 25 から 0.5 ~ 0.9 に低下しました (!)。これほど大きな負荷が発生するとはfunc_odbc.conf思いませんでした。AGI

関連情報