Hi,
I am testing an environment where we have two servers running Asterisk 11.6.0. There is a SIP trunk between both servers. Then, as soon as a “tunnel” (created with confbridge application) between both servers is created the CPU goes up. The more tunnels we have the more high CPU goes up.
2.6.32-431.20.3.el6.x86_64
CentOS release 6.5 (Final)
Asterisk 11.6.0
Server1_ -> TNS-ES-SE-TS1 / 172.19.56.23
sip.conf
[toTNS-ES-SE-TS2]
type=peer
host=172.19.56.24
context=InVADEDialler
disallow=all
allow=all
canreinvite=no
insecure=port,invite
Server2_ -> TNS-ES-SE-TS2 / 172.19.56.24
sip.conf
[toTNS-ES-SE-TS1]
type=peer
host=172.19.56.23
context=InVADEDialler
disallow=all
allow=all
canreinvite=no
insecure=port,invite
onfbridge.conf (same in both sites)
[invadeconf_user]
type=user
music_on_hold_class=default
quiet=no
dsp_drop_silence=yes
dsp_talking_threshold=128
dsp_silence_threshold=2000
denoise=yes
jitterbuffer=yes
dtmf_passthrough=yes
announce_join_leave=no
[invadeconf_userq]
type=user
music_on_hold_class=default
quiet=yes
dsp_drop_silence=yes
dsp_talking_threshold=128
dsp_silence_threshold=2000
denoise=yes
jitterbuffer=yes
dtmf_passthrough=yes
announce_join_leave=no
[invadeconf_bridge]
type=bridge
max_members=15
;record_conference=yes
;record_file=</path/to/file>
;internal_sample_rate=auto
;mixing_interval=40
sound_join
sound_leave
extensions.conf (same in both sites)
[InVADEDialler]
exten => 8000,1,ConfBridge(8000,invadeconf_bridge,invadeconf_userq)
exten => 8001,1,ConfBridge(8001,invadeconf_bridge,invadeconf_userq)
exten => 8002,1,ConfBridge(8002,invadeconf_bridge,invadeconf_userq)
TNS-ES-SE-TS1*CLI> sip show peer toTNS-ES-SE-TS2
- Name : toTNS-ES-SE-TS2
Description :
Secret :
MD5Secret :
Remote Secret:
Context : InVADEDialler
Record On feature : automon
Record Off feature : automon
Subscr.Cont. :
Language :
Tonezone :
AMA flags : Unknown
Transfer mode: open
CallingPres : Presentation Allowed, Not Screened
Callgroup :
Pickupgroup :
Named Callgr :
Nam. Pickupgr:
MOH Suggest :
Mailbox :
VM Extension : asterisk
LastMsgsSent : 0/0
Call limit : 0
Max forwards : 0
Dynamic : No
Callerid : “” <>
MaxCallBR : 384 kbps
Expire : -1
Insecure : port,invite
Force rport : Auto (No)
Symmetric RTP: No
ACL : No
DirectMedACL : No
T.38 support : No
T.38 EC mode : Unknown
T.38 MaxDtgrm: -1
DirectMedia : No
PromiscRedir : No
User=Phone : No
Video Support: No
Text Support : No
Ign SDP ver : No
Trust RPID : No
Send RPID : No
Subscriptions: Yes
Overlap dial : No
DTMFmode : rfc2833
Timer T1 : 500
Timer B : 32000
ToHost : 172.19.56.24
Addr->IP : 172.19.56.24:5060
Defaddr->IP : (null)
Prim.Transp. : UDP
Allowed.Trsp : UDP
Def. Username:
SIP Options : (none)
Codecs : (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|speex16|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14|testlaw|g719|speex32|slin12|slin24|slin32|slin44|slin48|slin96|slin192|silk8|silk12|silk16|silk24)
Codec Order : (none)
Auto-Framing : No
Status : Unmonitored
Useragent :
Reg. Contact :
Qualify Freq : 60000 ms
Keepalive : 0 ms
Sess-Timers : Accept
Sess-Refresh : uas
Sess-Expires : 1800 secs
Min-Sess : 90 secs
RTP Engine : asterisk
Parkinglot :
Use Reason : No
Encryption : No
Then, from Asterisk CLI we originate the call to create the tunnel:
TNS-ES-SE-TS1*CLI> originate SIP/toTNS-ES-SE-TS2/8000 extension 8000@InVADEDialler
TNS-ES-SE-TS1*CLI> core show channel SIP/toTNS-ES-SE-TS2-00000000
– General –
Name: SIP/toTNS-ES-SE-TS2-00000000
Type: SIP
UniqueID: 1407314940.0
LinkedID: 1407314940.0
Caller ID: (N/A)
Caller ID Name: (N/A)
Connected Line ID: (N/A)
Connected Line ID Name: (N/A)
Eff. Connected Line ID: (N/A)
Eff. Connected Line ID Name: (N/A)
DNID Digits: (N/A)
Language: en
State: Up (6)
Rings: 0
NativeFormats: (ulaw)
WriteFormat: slin
ReadFormat: slin
WriteTranscode: Yes (slin)->(ulaw)
ReadTranscode: Yes (ulaw)->(slin)
1st File Descriptor: 150
Frames in: 106825
Frames out: 53304
Time to Hangup: 0
Elapsed Time: 0h17m46s
Direct Bridge:
Indirect Bridge:
– PBX –
Context: InVADEDialler
Extension: 8000
Priority: 1
Call Group: 0
Pickup Group: 0
Application: ConfBridge
Data: 8000,invadeconf_bridge,invadeconf_userq
Blocking in: ast_waitfor_nandfds
Call Identifer: [C-00000000]
Variables:
SIPCALLID=4bae0400094779c253faa5543fecbe5c@172.19.56.23:5060
CDR Variables:
level 1: dnid=
level 1: dst=8000
level 1: dcontext=InVADEDialler
level 1: channel=SIP/toTNS-ES-SE-TS2-00000000
level 1: lastapp=ConfBridge
level 1: lastdata=8000,invadeconf_bridge,invadeconf_userq
level 1: start=2014-08-06 10:49:00
level 1: answer=2014-08-06 10:49:00
level 1: duration=1066
level 1: billsec=1066
level 1: disposition=ANSWERED
level 1: amaflags=DOCUMENTATION
level 1: uniqueid=1407314940.0
level 1: linkedid=1407314940.0
level 1: sequence=0
Asterisk_Logs
[Aug 6 11:13:37] VERBOSE[2418][C-00000002] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[Aug 6 11:13:37] DEBUG[2418][C-00000002] chan_sip.c: – Done with adding codecs to SDP
[Aug 6 11:13:37] DEBUG[2418][C-00000002] chan_sip.c: Done building SDP. Settling with this capability: (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|speex16|ilbc|g726aal2|g722|slin16|siren7|siren14|g719|speex32|silk8|silk12|silk16|silk24)
[Aug 6 11:13:37] VERBOSE[2418][C-00000002] chan_sip.c:
ÿ<— Reliably Transmitting (no NAT) to 172.19.56.23:5060 —>
ÿSIP/2.0 200 OK
ÿVia: SIP/2.0/UDP 172.19.56.23:5060;branch=z9hG4bK36fd679a;received=172.19.56.23
ÿFrom: “Anonymous” sip:anonymous@anonymous.invalid;tag=as6448840f
ÿTo: sip:8000@172.19.56.24;tag=as65e068c9
ÿCall-ID: 4ea491311decb52c17b4ac1d28d9f46e@172.19.56.23:5060
ÿCSeq: 102 INVITE
ÿServer: Asterisk PBX 11.6.0
ÿAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ÿSupported: replaces, timer
ÿSession-Expires: 1800;refresher=uas
ÿContact: sip:8000@172.19.56.24:5060
ÿContent-Type: application/sdp
ÿRequire: timer
ÿContent-Length: 1309
ÿ
ÿv=0
ÿo=root 946938154 946938154 IN IP4 172.19.56.24
ÿs=Asterisk PBX 11.6.0
ÿc=IN IP4 172.19.56.24
ÿt=0 0
ÿm=audio 11072 RTP/AVP 4 3 0 8 112 5 7 18 110 97 111 9 102 115 116 117 96 100 107 108 10 118 119 101
ÿa=rtpmap:4 G723/8000
ÿa=fmtp:4 annexa=no
ÿa=rtpmap:3 GSM/8000
ÿa=rtpmap:0 PCMU/8000
ÿa=rtpmap:8 PCMA/8000
ÿa=rtpmap:112 AAL2-G726-32/8000
ÿa=rtpmap:5 DVI4/8000
ÿa=rtpmap:7 LPC/8000
ÿa=rtpmap:18 G729/8000
ÿa=fmtp:18 annexb=no
ÿa=rtpmap:110 speex/8000
ÿa=rtpmap:97 iLBC/8000
ÿa=fmtp:97 mode=30
ÿa=rtpmap:111 G726-32/8000
ÿa=rtpmap:9 G722/8000
ÿa=rtpmap:102 G7221/16000
ÿa=fmtp:102 bitrate=32000
ÿa=rtpmap:115 G7221/32000
ÿa=fmtp:115 bitrate=48000
ÿa=rtpmap:116 G719/48000
ÿa=fmtp:116 bitrate=64000
ÿa=rtpmap:117 speex/16000
ÿa=rtpmap:96 SILK/8000
ÿa=fmtp:96 maxaveragebitrate=10000
ÿa=fmtp:96 usedtx=0
ÿa=fmtp:96 useinbandfec=1
ÿa=rtpmap:100 SILK/12000
ÿa=fmtp:100 maxaveragebitrate=12000
ÿa=fmtp:100 usedtx=0
ÿa=fmtp:100 useinbandfec=1
ÿa=rtpmap:107 SILK/16000
ÿa=fmtp:107 maxaveragebitrate=20000
ÿa=fmtp:107 usedtx=0
ÿa=fmtp:107 useinbandfec=1
ÿa=rtpmap:108 SILK/24000
ÿa=fmtp:108 maxaveragebitrate=30000
ÿa=fmtp:108 usedtx=0
ÿa=fmtp:108 useinbandfec=1
ÿa=rtpmap:10 L16/8000
ÿa=rtpmap:118 L16/16000
ÿa=rtpmap:119 speex/32000
ÿa=rtpmap:101 telephone-event/8000
ÿa=fmtp:101 0-16
ÿa=ptime:20
ÿa=sendrecv
ÿ
ÿ<------------>
[Aug 6 11:13:37] DEBUG[2418][C-00000002] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #131
[Aug 6 11:13:37] DEBUG[2418][C-00000002] chan_sip.c: Trying to put ‘SIP/2.0 200’ onto UDP socket destined for 172.19.56.23:5060
[Aug 6 11:13:37] VERBOSE[1932] chan_sip.c:
ÿ<— SIP read from UDP:172.19.56.23:5060 —>
ÿACK sip:8000@172.19.56.24:5060 SIP/2.0
ÿVia: SIP/2.0/UDP 172.19.56.23:5060;branch=z9hG4bK75ad3f09
ÿMax-Forwards: 70
ÿFrom: “Anonymous” sip:anonymous@anonymous.invalid;tag=as6448840f
ÿTo: sip:8000@172.19.56.24;tag=as65e068c9
ÿContact: sip:anonymous@172.19.56.23:5060
ÿCall-ID: 4ea491311decb52c17b4ac1d28d9f46e@172.19.56.23:5060
ÿCSeq: 102 ACK
ÿUser-Agent: Asterisk PBX 11.6.0
ÿContent-Length: 0
ÿ
ÿ<------------->
[Aug 6 11:13:37] DEBUG[1932] chan_sip.c: Header 0 [ 38]: ACK sip:8000@172.19.56.24:5060 SIP/2.0
[Aug 6 11:13:37] DEBUG[1932] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 172.19.56.23:5060;branch=z9hG4bK75ad3f09
[Aug 6 11:13:37] DEBUG[1932] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70
[Aug 6 11:13:37] DEBUG[1932] chan_sip.c: Header 3 [ 66]: From: “Anonymous” sip:anonymous@anonymous.invalid;tag=as6448840f
[Aug 6 11:13:37] DEBUG[1932] chan_sip.c: Header 4 [ 42]: To: sip:8000@172.19.56.24;tag=as65e068c9
[Aug 6 11:13:37] DEBUG[1932] chan_sip.c: Header 5 [ 42]: Contact: sip:anonymous@172.19.56.23:5060
[Aug 6 11:13:37] DEBUG[1932] chan_sip.c: Header 6 [ 59]: Call-ID: 4ea491311decb52c17b4ac1d28d9f46e@172.19.56.23:5060
[Aug 6 11:13:37] DEBUG[1932] chan_sip.c: Header 7 [ 13]: CSeq: 102 ACK
[Aug 6 11:13:37] DEBUG[1932] chan_sip.c: Header 8 [ 31]: User-Agent: Asterisk PBX 11.6.0
[Aug 6 11:13:37] DEBUG[1932] chan_sip.c: Header 9 [ 17]: Content-Length: 0
[Aug 6 11:13:37] VERBOSE[1932] chan_sip.c: — (10 headers 0 lines) —
[Aug 6 11:13:37] DEBUG[1932] chan_sip.c: = Looking for Call ID: 4ea491311decb52c17b4ac1d28d9f46e@172.19.56.23:5060 (Checking From) --From tag as6448840f --To-tag as65e068c9
[Aug 6 11:13:37] DEBUG[1932][C-00000002] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[Aug 6 11:13:37] DEBUG[1932][C-00000002] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #131
[Aug 6 11:13:37] DEBUG[1932][C-00000002] chan_sip.c: Stopping retransmission on ‘4ea491311decb52c17b4ac1d28d9f46e@172.19.56.23:5060’ of Response 102: Match Found
[Aug 6 11:13:37] DEBUG[2418][C-00000002] res_rtp_asterisk.c: 0x7fc54c016820 – Probation learning mode pass with source address 172.19.56.23:13108
[Aug 6 11:13:37] DEBUG[2418][C-00000002] app_confbridge.c: Trying to find conference bridge ‘8000’
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Bridge technology simple_bridge does not have the capabilities we need.
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Bridge technology multiplexed_bridge does not have the capabilities we need.
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Chose bridge technology softmix
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Giving bridge technology softmix the bridge structure 0x7fc4cc001cb8 to setup
[Aug 6 11:13:37] DEBUG[2418][C-00000002] app_confbridge.c: Created conference ‘8000’ and linked to container.
[Aug 6 11:13:37] DEBUG[2418][C-00000002] devicestate.c: device ‘confbridge:8000’ state ‘2’
[Aug 6 11:13:37] DEBUG[2418][C-00000002] confbridge/conf_state.c: Changing conference ‘8000’ state from EMPTY to SINGLE
[Aug 6 11:13:37] DEBUG[1958] app_queue.c: Device ‘confbridge:8000’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Joining bridge channel 0x7fc4cc004528 to bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Added channel SIP/toTNS-ES-SE-TS1-00000002(0x7fc54c019168) to bridge array on 0x7fc4cc001cb8, new count is 1
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Bridge technology softmix wants to read any of formats (slin) but channel has ulaw
[Aug 6 11:13:37] DEBUG[2418][C-00000002] channel.c: Set channel SIP/toTNS-ES-SE-TS1-00000002 to read format slin
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Bridge 0x7fc4cc001cb8 put channel SIP/toTNS-ES-SE-TS1-00000002 into read format slin
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Bridge technology softmix wants to write any of formats (slin) but channel has ulaw
[Aug 6 11:13:37] DEBUG[2418][C-00000002] channel.c: Set channel SIP/toTNS-ES-SE-TS1-00000002 to write format slin
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Bridge 0x7fc4cc001cb8 put channel SIP/toTNS-ES-SE-TS1-00000002 into write format slin
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Giving bridge technology softmix notification that 0x7fc4cc004528 is joining bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21
[Aug 6 11:13:37] DEBUG[2418][C-00000002] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Starting a bridge thread for bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2419][C-00000002] bridging.c: Started bridge thread for 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2419][C-00000002] bridging.c: Launching bridge thread function 0x7fc55fc1d5d0 for bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw
[Aug 6 11:13:37] DEBUG[2418][C-00000002] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
[Aug 6 11:13:37] DEBUG[2418][C-00000002] bridging.c: Going into a multithreaded waitfor for bridge channel 0x7fc4cc004528 of bridge 0x7fc4cc001cb8
…
…
I have tried using default_user and default_bridge in the confbridge.conf, also tried using different codecs in the SIP trunk between servers but the output is always the same, high CPU as soon as a confbridge is created.
Any help will be appreciated.