[asterisk-bugs] [JIRA] (ASTERISK-29058) app_bridgewait: On timeout returning back to wrong context
Patrick Wakano (JIRA)
noreply at issues.asterisk.org
Tue Sep 1 20:13:43 CDT 2020
[ https://issues.asterisk.org/jira/browse/ASTERISK-29058?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Patrick Wakano updated ASTERISK-29058:
--------------------------------------
Attachment: debug_log_29058.txt
cli_asterisk_29058.txt
Extra logs as requested
> app_bridgewait: On timeout returning back to wrong context
> ----------------------------------------------------------
>
> Key: ASTERISK-29058
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-29058
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: Applications/app_bridgewait, Bridges/bridge_holding, Bridges/bridge_simple, PBX/General
> Affects Versions: 16.8.0
> Reporter: Patrick Wakano
> Assignee: Patrick Wakano
> Severity: Minor
> Attachments: cli_asterisk_29058.txt, debug_log_29058.txt
>
>
> It was found a scenario where the timeout of the BridgeWait application is not resuming the execution on the correct context, but executing previous context.
> The scenario is complicate but reproducible 100% of the time if being done in this way:
> So these are the necessary dialplan contexts:
> {noformat}
> [originate-leg2]
> exten => s,1,Dial(SIP/9000,60,U(orig-ans))
> [orig-ans]
> exten => s,1,Set(DB(test/chan)=${CHANNEL})
> same => n,Return()
> [originate-leg1]
> exten => s,1,NoOp(${CONTEXT})
> same => n,ChannelRedirect(${DB(test/chan)},bridgewait-forever,s,1)
> [bridgewait-forever]
> exten => s,1,BridgeWait(1,,e(n))
> same => n,NoOp(This should not happen)
> same => n,Hangup()
> [bridgewait-loop]
> exten => s,1(pl),Playback(pls-stay-on-line)
> ;same => n,Park(,Rsc(bridgewait-loop,s,pl)t(10))
> ;same => n,Wait(10)
> same => n,BridgeWait(1,,e(n)S(10))
> same => n,Goto(pl)
> [originate-to-moh]
> exten => s,1,Answer()
> same => n,MusicOnHold(native-random)
> [bridge-to-moh]
> exten => s,1,Wait(0.1)
> same => n,Bridge(${DB(test/chan)},p)
> {noformat}
> And this are the necessary CLI commands:
> {noformat}
> originate Local/s at originate-leg2 extension s at originate-leg1
> originate Local/s at originate-to-moh extension s at bridge-to-moh
> channel redirect SIP/9000-00000002 bridgewait-loop,s,1
> {noformat}
> In this scenario the 1st originate command initiates a call to someone. This is done via a Local channel, which first dials the destination and after answered, the answered channel is redirected to a context with a BridgeWait with no timeout, so channel stays there waiting to be connected.
> Later on another originate happens, which takes the channel out of the BridgeWait and Bridges it to someone else, in this case a Local channel just playing MOH.
> At some other point in time, a Redirect command is done on the channel that is bridged. This time the channel is sent to a context with a BridgeWait that has a timeout. The timeout idea is to loop a playback every so often, however at this point once the timeout of the BridgeWait happens the channel executes the wrong context. It is going back to the context of the first BridgeWait (the one with no timeout and where it was before the Bridge). Then the playback loop doesn't happen and the channel starts executing a dialplan it is not supposed to go.
> Notes:
> - The second originate must happen to reproduce the problem. Looks like (my guess) the Bridge that is done in there plays an important role for the problem.
> - If the BridgeWait with timeout is replaced by a simply Wait or by a Park, the problem does not happen.
> These are the logs for this case:
> {noformat}
> pstn8*CLI> originate Local/s at originate-leg2 extension s at originate-leg1
> [Aug 31 20:30:28] -- Called s at originate-leg2
> [Aug 31 20:30:28] -- Executing [s at originate-leg2:1] Dial("Local/s at originate-leg2-00000005;2", "SIP/9000,60,U(orig-ans)") in new stack
> [Aug 31 20:30:28] == Using SIP RTP CoS mark 5
> [Aug 31 20:30:28] -- Called SIP/9000
> [Aug 31 20:30:28] -- SIP/9000-00000002 is ringing
> [Aug 31 20:30:28] -- Local/s at originate-leg2-00000005;1 is ringing
> [Aug 31 20:30:30] > 0x555689cc3740 -- Strict RTP learning after remote address set to: 172.28.128.200:8000
> [Aug 31 20:30:30] -- SIP/9000-00000002 answered Local/s at originate-leg2-00000005;2
> [Aug 31 20:30:30] -- SIP/9000-00000002 Internal Gosub(orig-ans,s,1) start
> [Aug 31 20:30:30] -- Executing [s at orig-ans:1] Set("SIP/9000-00000002", "DB(test/chan)=SIP/9000-00000002") in new stack
> [Aug 31 20:30:30] -- Executing [s at orig-ans:2] Return("SIP/9000-00000002", "") in new stack
> [Aug 31 20:30:30] == Spawn extension (pstn-outgoing, , 1) exited non-zero on 'SIP/9000-00000002'
> [Aug 31 20:30:30] -- SIP/9000-00000002 Internal Gosub(orig-ans,s,1) complete GOSUB_RETVAL=
> [Aug 31 20:30:30] -- Local/s at originate-leg2-00000005;1 answered
> [Aug 31 20:30:30] -- Executing [s at originate-leg1:1] NoOp("Local/s at originate-leg2-00000005;1", "originate-leg1") in new stack
> [Aug 31 20:30:30] -- Channel SIP/9000-00000002 joined 'simple_bridge' basic-bridge <26fc627c-8a1e-449f-8f56-58736fe2f2a1>
> [Aug 31 20:30:30] > 0x555689cc3740 -- Strict RTP switching to RTP target address 172.28.128.200:8000 as source
> [Aug 31 20:30:30] -- Channel Local/s at originate-leg2-00000005;2 joined 'simple_bridge' basic-bridge <26fc627c-8a1e-449f-8f56-58736fe2f2a1>
> [Aug 31 20:30:30] -- Executing [s at originate-leg1:2] ChannelRedirect("Local/s at originate-leg2-00000005;1", "SIP/9000-00000002,bridgewait-forever,s,1") in new stack
> [Aug 31 20:30:30] -- Auto fallthrough, channel 'Local/s at originate-leg2-00000005;1' status is 'UNKNOWN'
> [Aug 31 20:30:30] -- Channel Local/s at originate-leg2-00000005;2 left 'simple_bridge' basic-bridge <26fc627c-8a1e-449f-8f56-58736fe2f2a1>
> [Aug 31 20:30:30] == Spawn extension (originate-leg2, s, 1) exited non-zero on 'Local/s at originate-leg2-00000005;2'
> [Aug 31 20:30:30] -- Channel SIP/9000-00000002 left 'simple_bridge' basic-bridge <26fc627c-8a1e-449f-8f56-58736fe2f2a1>
> [Aug 31 20:30:30] -- Executing [s at bridgewait-forever:1] BridgeWait("SIP/9000-00000002", "1,,e(n)") in new stack
> [Aug 31 20:30:30] -- SIP/9000-00000002 is entering waiting bridge 1:7d9961a5-693c-4be4-be3b-6c148bb92465
> [Aug 31 20:30:30] -- Channel SIP/9000-00000002 joined 'holding_bridge' base-bridge <7d9961a5-693c-4be4-be3b-6c148bb92465>
> [Aug 31 20:30:35] > 0x555689cc3740 -- Strict RTP learning complete - Locking on source address 172.28.128.200:8000
> pstn8*CLI>
> pstn8*CLI> originate Local/s at originate-to-moh extension s at bridge-to-moh
> [Aug 31 20:30:37] -- Called s at originate-to-moh
> [Aug 31 20:30:37] -- Executing [s at originate-to-moh:1] Answer("Local/s at originate-to-moh-00000006;2", "") in new stack
> [Aug 31 20:30:37] -- Local/s at originate-to-moh-00000006;1 answered
> [Aug 31 20:30:37] -- Executing [s at bridge-to-moh:1] Wait("Local/s at originate-to-moh-00000006;1", "0.1") in new stack
> [Aug 31 20:30:37] -- Executing [s at bridge-to-moh:2] Bridge("Local/s at originate-to-moh-00000006;1", "SIP/9000-00000002,p") in new stack
> [Aug 31 20:30:37] -- Channel SIP/9000-00000002 left 'holding_bridge' base-bridge <7d9961a5-693c-4be4-be3b-6c148bb92465>
> [Aug 31 20:30:37] -- Channel SIP/9000-00000002 joined 'simple_bridge' basic-bridge <67c70946-0b4d-44c9-b446-9d1303fe6fec>
> [Aug 31 20:30:37] -- Channel Local/s at originate-to-moh-00000006;1 joined 'simple_bridge' basic-bridge <67c70946-0b4d-44c9-b446-9d1303fe6fec>
> [Aug 31 20:30:37] -- <SIP/9000-00000002> Playing 'beep.slin' (language 'en')
> [Aug 31 20:30:37] -- Executing [s at originate-to-moh:2] MusicOnHold("Local/s at originate-to-moh-00000006;2", "native-random") in new stack
> [Aug 31 20:30:37] -- Started music on hold, class 'native-random', on channel 'Local/s at originate-to-moh-00000006;2'
> pstn8*CLI>
> pstn8*CLI> channel redirect SIP/9000-00000002 bridgewait-loop,s,1
> Channel 'SIP/9000-00000002' successfully redirected to bridgewait-loop,s,1
> [Aug 31 20:30:51] -- Channel SIP/9000-00000002 left 'simple_bridge' basic-bridge <67c70946-0b4d-44c9-b446-9d1303fe6fec>
> [Aug 31 20:30:51] == Spawn extension (bridgewait-loop, s, 1) exited non-zero on 'SIP/9000-00000002'
> [Aug 31 20:30:51] -- Executing [s at bridgewait-loop:1] Playback("SIP/9000-00000002", "pls-stay-on-line") in new stack
> [Aug 31 20:30:51] -- Channel Local/s at originate-to-moh-00000006;1 left 'simple_bridge' basic-bridge <67c70946-0b4d-44c9-b446-9d1303fe6fec>
> [Aug 31 20:30:51] -- Auto fallthrough, channel 'Local/s at originate-to-moh-00000006;1' status is 'UNKNOWN'
> [Aug 31 20:30:51] -- Stopped music on hold on Local/s at originate-to-moh-00000006;2
> [Aug 31 20:30:51] == Spawn extension (originate-to-moh, s, 2) exited non-zero on 'Local/s at originate-to-moh-00000006;2'
> [Aug 31 20:30:51] -- <SIP/9000-00000002> Playing 'pls-stay-on-line.slin' (language 'en')
> pstn8*CLI>
> [Aug 31 20:30:56] -- Executing [s at bridgewait-loop:2] BridgeWait("SIP/9000-00000002", "1,,e(n)S(10)") in new stack
> [Aug 31 20:30:56] -- SIP/9000-00000002 is entering waiting bridge 1:3efeef33-cda6-43d1-8332-90256f0cfd97
> [Aug 31 20:30:56] -- Channel SIP/9000-00000002 joined 'holding_bridge' base-bridge <3efeef33-cda6-43d1-8332-90256f0cfd97>
> pstn8*CLI>
> [Aug 31 20:31:06] -- Channel SIP/9000-00000002 timed out.
> [Aug 31 20:31:06] -- Channel SIP/9000-00000002 left 'holding_bridge' base-bridge <3efeef33-cda6-43d1-8332-90256f0cfd97>
> [Aug 31 20:31:06] == Spawn extension (bridgewait-forever, s, 2) exited non-zero on 'SIP/9000-00000002'
> [Aug 31 20:31:06] -- Executing [s at bridgewait-forever:2] NoOp("SIP/9000-00000002", "This should not happen") in new stack
> [Aug 31 20:31:06] -- Executing [s at bridgewait-forever:3] Hangup("SIP/9000-00000002", "") in new stack
> [Aug 31 20:31:06] == Spawn extension (bridgewait-forever, s, 3) exited non-zero on 'SIP/9000-00000002'
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.2#6252)
More information about the asterisk-bugs
mailing list