[asterisk-bugs] [Asterisk 0016507]: Exceptionally long voice queue length with chan_iax2 + res_timing_pthread causes high CPU usage

Asterisk Bug Tracker noreply at bugs.digium.com
Fri May 21 06:29:57 CDT 2010


A NOTE has been added to this issue. 
====================================================================== 
https://issues.asterisk.org/view.php?id=16507 
====================================================================== 
Reported By:                marcelloceschia
Assigned To:                
====================================================================== 
Project:                    Asterisk
Issue ID:                   16507
Category:                   Channels/chan_iax2
Reproducibility:            always
Severity:                   major
Priority:                   normal
Status:                     acknowledged
Asterisk Version:           SVN 
JIRA:                       SWP-833 
Regression:                 Yes 
Reviewboard Link:            
SVN Branch (only for SVN checkouts, not tarball releases): N/A 
SVN Revision (number only!):  
Request Review:              
====================================================================== 
Date Submitted:             2009-12-23 04:58 CST
Last Modified:              2010-05-21 06:29 CDT
====================================================================== 
Summary:                    Exceptionally long voice queue length with chan_iax2
+ res_timing_pthread causes high CPU usage
Description: 
When making a call using iax channel, i have a high cpu usage
https://issues.asterisk.org/view.php?id=18#c97%
This does not only happens while transcoding audio, also with the same
codecs on both sides.

after a short time, i get the following cli output:

[Dec 23 11:45:29] WARNING[12300]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to IAX2/diax-6892

Calling sip2sip has a cpu usage about 1.5% per call
======================================================================
Relationships       ID      Summary
----------------------------------------------------------------------
duplicate of        0015609 [patch] WARNING[23025]: channel.c:952 _...
related to          0017214 Exceptionally long voice queuing when u...
====================================================================== 

---------------------------------------------------------------------- 
 (0122238) keitsi (reporter) - 2010-05-21 06:29
 https://issues.asterisk.org/view.php?id=16507#c122238 
---------------------------------------------------------------------- 
Hi,

I had a very, very similar issue.
I don't know if it should be reported as a seperate bug or not, but
definitely it seems related!

The errors shown in CLI were:

------------------------
voip2*CLI>
[May 21 03:28:35] WARNING[26473]: chan_iax2.c:3330 __attempt_transmit: Max
retries exceeded to host 10.240.100.34 on IAX2/someiaxclient-7248 (type =
6, subclass = 2, ts=1320274, seqno=76)
  == Spawn extension (innovaphone-5, 0400998371, 1) exited non-zero on
'IAX2/someiaxclient-7248'
    -- Hungup 'IAX2/someiaxclient-7248'
[May 21 03:28:39] WARNING[26473]: chan_iax2.c:3330 __attempt_transmit: Max
retries exceeded to host 10.240.100.123 on IAX2/anotheriaxclient-1822 (type
= 6, subclass = 11, ts=374302, seqno=100)
[May 21 03:28:39] WARNING[26832]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
[May 21 03:28:39] WARNING[26826]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
[May 21 03:28:39] WARNING[26854]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
[May 21 03:28:39] WARNING[26810]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
[May 21 03:28:39] WARNING[26857]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
[May 21 03:28:39] WARNING[26822]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
[May 21 03:28:39] WARNING[26817]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
[May 21 03:28:39] WARNING[26852]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
[May 21 03:28:39] WARNING[26807]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
[May 21 03:28:39] WARNING[26811]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
[May 21 03:28:39] WARNING[26819]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
[May 21 03:28:39] WARNING[26802]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
[May 21 03:28:39] WARNING[26806]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
[May 21 03:28:39] WARNING[26796]: channel.c:1045 __ast_queue_frame:
Exceptionally long voice queue length queuing to
IAX2/anotheriaxclient-1822
    -- Registered IAX2 'anotheriaxclient' (AUTHENTICATED) at
10.240.100.123:4569
  == Spawn extension (innovaphone-4, 0400998371, 1) exited non-zero on
'IAX2/anotheriaxclient-1822'
    -- Hungup 'IAX2/anotheriaxclient-1822'
    -- Registered IAX2 'someiaxclient' (AUTHENTICATED) at
10.240.100.34:4569
    -- Registered IAX2 'someiaxclient' (AUTHENTICATED) at
10.240.100.123:4176
    -- Registered IAX2 'someiaxclient' (AUTHENTICATED) at
10.240.100.34:4569
------------------------

With just 2 calls, I could get CPU usage 40 - 80% with P4 processor, loads
1-2.
3 calls, loads were about https://issues.asterisk.org/view.php?id=12#c8 and CPU
at max (95%+).
4 calls, loads were about https://issues.asterisk.org/view.php?id=14#c20+ and
CPU at max (95%+), calls drop
eventually.

I tried other timing settings, but they didn't change anything.
I added noload => res_timing_pthreads.so  and  load => res_timing_dahdi.so
to modules.conf, and also tried changing internal_timing in asterisk.conf
(both yes and no). No help here.

The setup was:
custom iax2 client software --- iax2+speex --- asterisk iax2 server ---
asterisk h323 server --- ulaw/h323 --- h323 client --- GSM modem --- GSM
network

Resolution:
I switched the h323 codec from ulaw to alaw, and bam, NO MORE PROBLEMS!
Speex was used in iax side, but on h323 side ulaw was used.
Loads were then near zero, and CPU usage less than 10% all the way up to 6
calls.
My guess is that it's some kind of thread locking issue related to ulaw
and/or h323/iax2.

System information:
Distro: Ubuntu 10.04
Asterisk: Stock 1.6.2.5 with ubuntu 10.04 LTS patches (1.6.2.5-0ubuntu1)
HW: P4 with 512MB RAM
Kernel: 2.6.32-21-generic-pae https://issues.asterisk.org/view.php?id=32-Ubuntu
SMP

root at voip2:~# dpkg -l|grep asterisk
ii  asterisk                            1:1.6.2.5-0ubuntu1               
Open Source Private Branch Exchange (PBX)
ii  asterisk-chan-sebi                  0.0.20100520-1                   
chan_sebi for asterisk
ii  asterisk-config                     1:1.6.2.5-0ubuntu1               
Configuration files for Asterisk
ii  asterisk-dev                        1:1.6.2.5-0ubuntu1               
Development files for Asterisk
ii  asterisk-h323                       1:1.6.2.5-0ubuntu1               
H.323 protocol support for Asterisk
ii  asterisk-sounds-main                1:1.6.2.5-0ubuntu1               
Core Sound files for Asterisk (English)
root at voip2:~# uname -a
Linux voip2 2.6.32-21-generic-pae
https://issues.asterisk.org/view.php?id=32-Ubuntu SMP Fri Apr 16 09:39:35 UTC
2010 i686 GNU/Linux
root at voip2:~# cat /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 15
model           : 2
model name      : Intel(R) Pentium(R) 4 CPU 2.66GHz
stepping        : 9
cpu MHz         : 2660.292
cache size      : 512 KB
fdiv_bug        : no
hlt_bug         : no
f00f_bug        : no
coma_bug        : no
fpu             : yes
fpu_exception   : yes
cpuid level     : 2
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic mtrr pge mca
cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe up pebs bts
cid xtpr
bogomips        : 5320.58
clflush size    : 64
cache_alignment : 128
address sizes   : 36 bits physical, 32 bits virtual
power management:

root at voip2:~# lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 10.04 LTS
Release:        10.04
Codename:       lucid 

Issue History 
Date Modified    Username       Field                    Change               
====================================================================== 
2010-05-21 06:29 keitsi         Note Added: 0122238                          
======================================================================




More information about the asterisk-bugs mailing list