[Home]

Summary:ASTERISK-15727: 100% CPU load at feature startup
Reporter:ujvu (ujvu)Labels:
Date Opened:2010-03-02 03:21:45.000-0600Date Closed:2011-06-07 14:04:58
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:1. 251 calls 250
2. 250 picks up and talks to 251
3. 250 dials *5, feature tr1 starts, 250 hangs up
4. 252 rings (macro-new_redirect)
5. 252 picks up and talks to 251
6. end of call

Points 4-6 has 100% cpu load

****** ADDITIONAL INFORMATION ******

features.conf:
[applicationmap]
tr1 => *5,peer/callee,Macro,new_redirect

extensions.conf:
[globals]
DYNAMIC_FEATURES=tr1
[default]
exten => _2XX, 1, Dial(SIP/${EXTEN})
[macro-new_redirect]
exten => s, 1, ChannelRedirect(${BRIDGEPEER},beep_hangup,s,1)
exten => s, n, Dial(Local/252)
[beep_hangup]
exten => s, 1, Playback(beep)
exten => s, n, Hangup

full.log with dtmf:
[Mar  2 10:12:23] VERBOSE[24363] netsock.c:   == Using SIP RTP CoS mark 5
[Mar  2 10:12:23] VERBOSE[24690] pbx.c:     -- Executing [250@default:1] Dial("SIP/251-00000014", "SIP/250") in new stack
[Mar  2 10:12:23] VERBOSE[24690] netsock.c:   == Using SIP RTP CoS mark 5
[Mar  2 10:12:23] VERBOSE[24690] app_dial.c:     -- Called 250
[Mar  2 10:12:23] VERBOSE[24690] app_dial.c:     -- SIP/250-00000015 is ringing
[Mar  2 10:12:25] VERBOSE[24690] app_dial.c:     -- SIP/250-00000015 answered SIP/251-00000014
[Mar  2 10:12:47] DTMF[24690] channel.c: DTMF begin '*' received on SIP/250-00000015
[Mar  2 10:12:47] DTMF[24690] channel.c: DTMF begin ignored '*' on SIP/250-00000015
[Mar  2 10:12:47] DTMF[24690] channel.c: DTMF end '*' received on SIP/250-00000015, duration 120 ms
[Mar  2 10:12:47] DTMF[24690] channel.c: DTMF end passthrough '*' on SIP/250-00000015
[Mar  2 10:12:47] DTMF[24690] channel.c: DTMF begin '5' received on SIP/250-00000015
[Mar  2 10:12:47] DTMF[24690] channel.c: DTMF begin ignored '5' on SIP/250-00000015
[Mar  2 10:12:47] DTMF[24690] channel.c: DTMF end '5' received on SIP/250-00000015, duration 80 ms
[Mar  2 10:12:47] DTMF[24690] channel.c: DTMF end passthrough '5' on SIP/250-00000015
[Mar  2 10:12:47] VERBOSE[24690] features.c:     --  Feature Found: tr1 exten: tr1
[Mar  2 10:12:47] VERBOSE[24690] pbx.c:     -- Executing [s@macro-new_redirect:1] ChannelRedirect("SIP/251-00000014", "SIP/250-00000015,beep_hangup,s,1") in new stack
[Mar  2 10:12:47] VERBOSE[24692] pbx.c:     -- Executing [s@beep_hangup:1] Playback("SIP/250-00000015", "beep") in new stack
[Mar  2 10:12:47] VERBOSE[24692] file.c:     -- <SIP/250-00000015> Playing 'beep.gsm' (language 'en')
[Mar  2 10:12:47] VERBOSE[24690] pbx.c:     -- Executing [s@macro-new_redirect:2] Dial("SIP/251-00000014", "Local/252") in new stack
[Mar  2 10:12:47] VERBOSE[24693] pbx.c:     -- Executing [252@default:1] Dial("Local/252@default-750b;2", "SIP/252") in new stack
[Mar  2 10:12:47] VERBOSE[24693] netsock.c:   == Using SIP RTP CoS mark 5
[Mar  2 10:12:47] VERBOSE[24693] app_dial.c:     -- Called 252
[Mar  2 10:12:47] VERBOSE[24690] app_dial.c:     -- Called 252
[Mar  2 10:12:47] VERBOSE[24693] app_dial.c:     -- SIP/252-00000016 is ringing
[Mar  2 10:12:47] VERBOSE[24690] app_dial.c:     -- Local/252@default-750b;1 is ringing
[Mar  2 10:12:48] VERBOSE[24692] pbx.c:     -- Executing [s@beep_hangup:2] Hangup("SIP/250-00000015", "") in new stack
[Mar  2 10:12:48] VERBOSE[24692] pbx.c:   == Spawn extension (beep_hangup, s, 2) exited non-zero on 'SIP/250-00000015'
[Mar  2 10:12:57] VERBOSE[24693] app_dial.c:     -- SIP/252-00000016 answered Local/252@default-750b;2
[Mar  2 10:12:57] VERBOSE[24690] app_dial.c:     -- Local/252@default-750b;1 answered SIP/251-00000014
[Mar  2 10:12:57] WARNING[24693] chan_local.c: New unhandled control frame added!!!
[Mar  2 10:12:57] VERBOSE[24690] rtp.c:     -- Packet2Packet bridging SIP/251-00000014 and SIP/252-00000016
[Mar  2 10:12:57] VERBOSE[24693] pbx.c:   == Spawn extension (default, 252, 1) exited non-zero on 'Local/252@default-750b;2'
[Mar  2 10:13:16] VERBOSE[24690] app_macro.c:   == Spawn extension (macro-new_redirect, s, 2) exited non-zero on 'SIP/251-00000014' in macro 'new_redirect'

top:
 PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
24686 root      20   0  381m  14m 6196 R 99.6  3.0   1:10.53 asterisk -vvvvvvvvvvvvvv
24691 antik     20   0 18824 1252  948 R  2.0  0.2   0:00.26 top

mainframe*CLI> core show version
Asterisk SVN-branch-1.6.1-r249492 built by antik @ mainframe on a x86_64 running Linux on 2010-02-23 14:05:19 UTC

antik@mainframe:~$ uname -a
Linux mainframe 2.6.26-2-amd64 #1 SMP Wed Aug 19 22:33:18 UTC 2009 x86_64 GNU/Linux
Comments:By: Leif Madsen (lmadsen) 2010-03-03 13:32:52.000-0600

This is likely expected behaviour, per the note in features.conf.sample:

; IMPORTANT NOTE: The applicationmap is not intended to be used for all Asterisk
;   applications. When applications are used in extensions.conf, they are executed
;   by the PBX core. In this case, these applications are executed outside of the
;   PBX core, so it does *not* make sense to use any application which has any
;   concept of dialplan flow. Examples of this would be things like Macro, Goto,
;   Background, WaitExten, and many more.
;
; Enabling these features means that the PBX needs to stay in the media flow and
; media will not be re-directed if DTMF is sent in the media stream.

By: ujvu (ujvu) 2010-03-05 14:36:11.000-0600

I thought that after moving res_features in the PBX core it stopped to be actual.  I solved the problem this way:

[macro-new_redirect]
exten => s, 1, ChannelRedirect(${BRIDGEPEER},beep_hangup,s,1)
exten => s, n, ChannelRedirect(${CHANNEL},dial,s,1)

[beep_hangup]
exten => s, 1, Playback(beep)
exten => s, n, Hangup

[dial]
exten => s, 1, Dial(Local/252)
exten => s, n, Hangup