thr3ads.net - asterisk users - [Asterisk-Users] "Got clone lock for masquerade" crash [Dec 2005]

If this information is useful, please help other people find it:
Share via:

Benny Amorsen

2005-Dec-12 02:14 UTC

[Asterisk-Users] "Got clone lock for masquerade" crash

Several times asterisk has crashed with this message:

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


The 60111111 and the 12345678 numbers are fake, the rest of the log is
genuine. After this the log ends because asterisk is dead. Each time
asterisk crashed, the "Got clone lock for masquerade" appeared as the
last log entry -- and the log entry never appeared without a crash.

The crash originally happened with 1.2.0 but has recurred several
times after upgrading to 1.2.1.


/Benny

Benny Amorsen

2005-Dec-12 03:27 UTC

head link

[Asterisk-Users] Re: "Got clone lock for masquerade" crash

Now I have unintentionally reproduced the problem again. The good news
is that I have a 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
#5  0xb7841e0c in dial_exec (chan=0x818e500, data=0xb7582fe8) at app_dial.c:1600
#6  0x0808cdb3 in pbx_extension_helper (c=0x818e500, con=Variable
"con" is not available.
) at pbx.c:544
#7  0x0808e254 in __ast_pbx_run (c=0x818e500) at pbx.c:2220
#8  0x0808ee5c in pbx_thread (data=0x818e500) at pbx.c:2507
#9  0xb7fb4b80 in start_thread () from /lib/libpthread.so.0
#10 0xb7e989ce in clone () from /lib/libc.so.6


/Benny

asterisk users - Dec 2005 - "Got clone lock for masquerade" crash

[Asterisk-Users] "Got clone lock for masquerade" crash

[Asterisk-Users] Re: "Got clone lock for masquerade" crash