[Home]

Summary:ASTERISK-05819: Crash in ast_do_masquerade when forwarding call externally
Reporter:Benny Amorsen (amorsen)Labels:
Date Opened:2005-12-12 07:10:04.000-0600Date Closed:2011-06-07 14:00:20
Priority:CriticalRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:When someone sets their SIP phone to forward calls externally (through a SIP provider), asterisk sometimes crashes during the forward. I have placed log messages and backtrace in "additional information".

The crash may be related to using lines like these:

exten => _1234567[0-3]X,1,Set(GROUP()=active_calls)
exten => _1234567[0-3]X,2,GotoIf($[${GROUP_COUNT()} > ${simultaneous_calls}]?106)

to limit the number of simulatenous calls.

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

Log:

Dec 12 09:17:09 DEBUG[6792] chan_sip.c: Setting NAT on RTP to 0
Dec 12 09:17:09 DEBUG[6792] chan_sip.c: Checking SIP call limits for device
Dec 12 09:17:09 DEBUG[6792] chan_sip.c: build_route: Contact hop: <sip:56635399@172.31.0.8>
Dec 12 09:17:09 DEBUG[6781] channel.c: Avoiding initial deadlock for 'SIP/172.31.0.8-b7402a60'
Dec 12 09:17:09 VERBOSE[12050] logger.c:     -- Executing Set("SIP/172.31.0.8-b7402a60", "GROUP()=active_calls") in new stack
Dec 12 09:17:09 DEBUG[12050] pbx.c: Function result is '1'
Dec 12 09:17:09 DEBUG[12050] pbx.c: Expression result is '0'
Dec 12 09:17:09 VERBOSE[12050] logger.c:     -- Executing GotoIf("SIP/172.31.0.8-b7402a60", "0?106") in new stack
Dec 12 09:17:09 DEBUG[12050] pbx.c: Not taking any branch
Dec 12 09:17:09 VERBOSE[12050] logger.c:     -- Executing Dial("SIP/172.31.0.8-b7402a60", "SIP/703|30|t") in new stack
Dec 12 09:17:09 DEBUG[12050] chan_sip.c: Setting NAT on RTP to 0
Dec 12 09:17:09 DEBUG[12050] chan_sip.c: Outgoing Call for 703
Dec 12 09:17:09 VERBOSE[12050] logger.c:     -- Called 703
Dec 12 09:17:09 DEBUG[6792] chan_sip.c: Acked pending invite 102
Dec 12 09:17:09 DEBUG[6792] chan_sip.c: Stopping retransmission on '2e70354975d986574403e4340769c4a5@10.0.1.37' of Request 102: Match Found
Dec 12 09:17:09 VERBOSE[6792] logger.c:     -- Got SIP response 302 "Moved Temporarily" back from 10.0.13.73
Dec 12 09:17:09 DEBUG[6792] chan_sip.c: Found 302 Redirect to extension '6011111'
Dec 12 09:17:09 VERBOSE[12050] logger.c:     -- Now forwarding SIP/172.31.0.8-b7402a60 to 'Local/6011111@do_dial' (thanks to SIP/703-7e11)
Dec 12 09:17:09 DEBUG[12050] chan_sip.c: update_call_counter(703) - decrement call limit counter
Dec 12 09:17:09 VERBOSE[12052] logger.c:     -- Executing Set("Local/6011111@do_dial-9b9f,2", "GROUP()=active_calls") in new stack
Dec 12 09:17:09 DEBUG[12052] pbx.c: Function result is '2'
Dec 12 09:17:09 DEBUG[12052] pbx.c: Expression result is '0'
Dec 12 09:17:09 VERBOSE[12052] logger.c:     -- Executing GotoIf("Local/6011111@do_dial-9b9f,2", "0?106") in new stack
Dec 12 09:17:09 DEBUG[12052] pbx.c: Not taking any branch
Dec 12 09:17:09 VERBOSE[12052] logger.c:     -- Executing Set("Local/6011111@do_dial-9b9f,2", "CALLERID(all)=Foo <12345678>") in new stack
Dec 12 09:17:09 VERBOSE[12052] logger.c:     -- Executing Dial("Local/6011111@do_dial-9b9f,2", "SIP/6011111@lpbx01") in new stack
Dec 12 09:17:09 DEBUG[12052] chan_sip.c: Setting NAT on RTP to 0
Dec 12 09:17:09 DEBUG[12052] chan_sip.c: Outgoing Call for 6011111
Dec 12 09:17:09 VERBOSE[12052] logger.c:     -- Called 6011111@lpbx01
Dec 12 09:17:09 DEBUG[6792] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3be553f97980682632d627901f126462@10.0.1.37' Request 102: Found
Dec 12 09:17:09 DEBUG[6792] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3be553f97980682632d627901f126462@10.0.1.37' Request 102: Found
Dec 12 09:17:09 VERBOSE[12052] logger.c:     -- SIP/lpbx01-3fa5 is making progress passing it to Local/6011111@do_dial-9b9f,2
Dec 12 09:17:09 VERBOSE[12050] logger.c:     -- Local/6011111@do_dial-9b9f,1 is making progress passing it to SIP/172.31.0.8-b7402a60
Dec 12 09:17:13 DEBUG[6792] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3be553f97980682632d627901f126462@10.0.1.37' Request 102: Found
Dec 12 09:17:13 VERBOSE[12052] logger.c:     -- SIP/lpbx01-3fa5 is ringing
Dec 12 09:17:13 VERBOSE[12050] logger.c:     -- Local/6011111@do_dial-9b9f,1 is ringing
Dec 12 09:17:17 DEBUG[6792] chan_sip.c: Acked pending invite 102
Dec 12 09:17:17 DEBUG[6792] chan_sip.c: Stopping retransmission on '3be553f97980682632d627901f126462@10.0.1.37' of Request 102: Match Found
Dec 12 09:17:17 DEBUG[6792] chan_sip.c: build_route: Contact hop: <sip:6011111@172.31.0.8>
Dec 12 09:17:17 VERBOSE[12052] logger.c:     -- SIP/lpbx01-3fa5 answered Local/6011111@do_dial-9b9f,2
Dec 12 09:17:17 VERBOSE[12050] logger.c:     -- Local/6011111@do_dial-9b9f,1 stopped sounds
Dec 12 09:17:17 VERBOSE[12050] logger.c:     -- Local/6011111@do_dial-9b9f,1 answered SIP/172.31.0.8-b7402a60
Dec 12 09:17:17 DEBUG[6781] channel.c: Avoiding initial deadlock for 'SIP/172.31.0.8-b7402a60'
Dec 12 09:17:17 DEBUG[6792] chan_sip.c: Stopping retransmission on '431e26547924cdae252f47024fba9bb3@172.31.0.8' of Response 102: Match Found
Dec 12 09:17:17 DEBUG[12050] channel.c: Planning to masquerade channel SIP/172.31.0.8-b7402a60 into the structure of Local/6011111@do_dial-9b9f,2
Dec 12 09:17:17 DEBUG[12050] channel.c: Done planning to masquerade channel SIP/172.31.0.8-b7402a60 into the structure of Local/6011111@do_dial-9b9f,2
Dec 12 09:17:17 DEBUG[12050] chan_local.c: Not posting to queue since already masked on 'Local/6011111@do_dial-9b9f,1'
Dec 12 09:17:17 DEBUG[12052] channel.c: Got clone lock for masquerade on 'SIP/172.31.0.8-b7402a60' at 0xb7401dc4

Backtrace:

#0  0x08063c25 in ast_do_masquerade (original=0x818e500) at channel.c:2841
2841                    AST_LIST_INSERT_TAIL(&original->varshead, AST_LIST_FIRST(&clone->varshead), entries);
(gdb) bt
#0  0x08063c25 in ast_do_masquerade (original=0x818e500) at channel.c:2841
#1  0x08065d1c in ast_read (chan=0x818e500) at channel.c:1792
#2  0x080686e5 in ast_channel_bridge (c0=0x818e500, c1=0x81bf6f0, config=0xb757ee6c, fo=0xb757e048, rc=0xb757e044) at channel.c:3248
#3  0xb7acc64e in ast_bridge_call (chan=0x818e500, peer=0x81bf6f0, config=0xb757ee6c) at res_features.c:1312
#4  0xb7840774 in dial_exec_full (chan=0x818e500, data=Variable "data" is not available.
) at app_dial.c:1558
ASTERISK-1  0xb7841e0c in dial_exec (chan=0x818e500, data=0xb7582fe8) at app_dial.c:1600
ASTERISK-2  0x0808cdb3 in pbx_extension_helper (c=0x818e500, con=Variable "con" is not available.
) at pbx.c:544
ASTERISK-3  0x0808e254 in __ast_pbx_run (c=0x818e500) at pbx.c:2220
ASTERISK-4  0x0808ee5c in pbx_thread (data=0x818e500) at pbx.c:2507
ASTERISK-5  0xb7fb4b80 in start_thread () from /lib/libpthread.so.0
ASTERISK-6 0xb7e989ce in clone () from /lib/libc.so.6
Comments:By: Kevin P. Fleming (kpfleming) 2005-12-13 09:42:26.000-0600

There was a major bug in the list handling macros just corrected in the last couple of days. Please try using SVN branch-1.2 instead of 1.2.1 and if you can still produce the problem then the bug can be reopened.