[asterisk-bugs] [JIRA] (ASTERISK-29058) app_bridgewait: On timeout returning back to wrong context after redirects

Patrick Wakano (JIRA) noreply at issues.asterisk.org
Thu Dec 3 19:46:16 CST 2020


    [ https://issues.asterisk.org/jira/browse/ASTERISK-29058?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=252939#comment-252939 ] 

Patrick Wakano commented on ASTERISK-29058:
-------------------------------------------

Ok Joshua, thank you. In case it helps here are some more findings I have for this case.
When the Bridge app is called, it sets the bridged channel to resume execution (the bridge_after idea) to its current context, exten and priority+1 or to the place the 'F' parameter sets.
Because the channel was bridged from the Bridge app and is then Redirected, the bridge is broken but the bridge_after destination is not cleared. So then later when the BridgeWait times out, the bridge_after logic is triggered but with the info from the last Bridge command.
So looks like there are 2 situations to be evaluated here. 
Should the Redirect command clear the bridge_after destination in case the redirected channel was bridged?
And should the BridgeWait app overwrite the bridge_after destination info its context, exten and priority+1? Also possibly, the BridgeWait could have added the parameter 'F' (as the Bridge has) so we could even set the the bridge_after destination to somewhere else in case of timeout.


> app_bridgewait: On timeout returning back to wrong context after redirects
> --------------------------------------------------------------------------
>
>                 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: Unassigned
>            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