[asterisk-bugs] [JIRA] (ASTERISK-26716) Channels with pre-dial handlers cannot be hung up via ARI

Tom Pawelek (JIRA) noreply at issues.asterisk.org
Sun Jan 15 18:19:11 CST 2017 

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

Tom Pawelek edited comment on ASTERISK-26716 at 1/15/17 6:17 PM:
-----------------------------------------------------------------

*UPDATE*: I have started digging in core_unreal and core_local. Here are my findings:

+Proper hangup+

[2017-01-15 18:35:16] DEBUG[963] core_local.c: *TMP* Entering local_hangup
[2017-01-15 18:35:16] DEBUG[963] core_unreal.c: *TMP* ast_unreal_lock_all(Local/13051002000-18001002000 at cont-fas-00000004;1) -> owner: Local/13051002000-18001002000 at cont-fas-00000004;1, chan: Local/13051002000-18001002000 at cont-fas-00000004;2
[2017-01-15 18:35:16] DEBUG[963] core_unreal.c: *TMP* Inside unreal_hangup(Local/13051002000-18001002000 at cont-fas-00000004;1) P_CHAN_IF_2
[2017-01-15 18:35:16] DEBUG[963] channel.c: *TMP* Received ast_queue_hangup_with_cause for Local/13051002000-18001002000 at cont-fas-00000004;2
[2017-01-15 18:35:16] DEBUG[963] channel.c: *TMP* ast_queue_hangup_with_cause returning 0 for Local/13051002000-18001002000 at cont-fas-00000004;2
[2017-01-15 18:35:16] DEBUG[963] core_local.c: *TMP* No_res
[2017-01-15 18:35:16] DEBUG[909] res_http_websocket.c: Writing websocket string of length 648
[2017-01-15 18:35:16] DEBUG[909] res_http_websocket.c: Writing websocket text frame, length 648
[2017-01-15 18:35:16] DEBUG[964][C-00000004] channel.c: Hanging up channel 'PJSIP/flowroute-00000003'
[2017-01-15 18:35:16] DEBUG[964][C-00000004] chan_pjsip.c: AST hangup cause 0 (no match found in PJSIP)
[2017-01-15 18:35:16] DEBUG[964][C-00000004] app_dial.c: Exiting with DIALSTATUS=CANCEL.
[2017-01-15 18:35:16] DEBUG[909] res_http_websocket.c: Writing websocket string of length 704
[2017-01-15 18:35:16] DEBUG[909] res_http_websocket.c: Writing websocket text frame, length 704
[2017-01-15 18:35:16] DEBUG[964][C-00000004] pbx.c: Spawn extension (cont-fas,13051002000-18001002000,5) exited non-zero on 'Local/13051002000-18001002000 at cont-fas-00000004;2'
[2017-01-15 18:35:16] DEBUG[859] devicestate.c: Changing state for Local/13051002000-18001002000 at cont-fas - state 1 (Not in use)
[2017-01-15 18:35:16] VERBOSE[964][C-00000004] pbx.c: Spawn extension (cont-fas, 13051002000-18001002000, 5) exited non-zero on 'Local/13051002000-18001002000 at cont-fas-00000004;2'
[2017-01-15 18:35:16] DEBUG[964][C-00000004] channel.c: Soft-Hanging (0x10) up channel 'Local/13051002000-18001002000 at cont-fas-00000004;2'
[2017-01-15 18:35:16] DEBUG[875] res_pjsip_session.c: Method is CANCEL
[2017-01-15 18:35:16] DEBUG[964][C-00000004] channel.c: Hanging up channel 'Local/13051002000-18001002000 at cont-fas-00000004;2'
[2017-01-15 18:35:16] DEBUG[875] res_config_pgsql.c: PostgreSQL query attempt 1
[2017-01-15 18:35:16] DEBUG[964][C-00000004] core_local.c: *TMP* Entering local_hangup
[2017-01-15 18:35:16] DEBUG[964][C-00000004] core_unreal.c: *TMP* ast_unreal_lock_all(Local/13051002000-18001002000 at cont-fas-00000004;2) -> owner: NULL, chan: Local/13051002000-18001002000 at cont-fas-00000004;2
[2017-01-15 18:35:16] DEBUG[964][C-00000004] core_local.c: *TMP* No_res
[2017-01-15 18:35:16] DEBUG[964][C-00000004] core_local.c: *TMP* Unlink_locals

+Zombie hangup+

[2017-01-15 18:35:39] DEBUG[978] channel.c: Hanging up channel 'Local/13051002000-18001002000 at cont-fas-00000005;1'
[2017-01-15 18:35:39] DEBUG[978] core_local.c: *TMP* Entering local_hangup
[2017-01-15 18:35:39] DEBUG[978] core_unreal.c: *TMP* ast_unreal_lock_all(Local/13051002000-18001002000 at cont-fas-00000005;1) -> owner: Local/13051002000-18001002000 at cont-fas-00000005;1, chan: Local/13051002000-18001002000 at cont-fas-00000005;2
[2017-01-15 18:35:39] DEBUG[978] core_unreal.c: *TMP* Inside unreal_hangup(Local/13051002000-18001002000 at cont-fas-00000005;1) P_CHAN_IF_2
[2017-01-15 18:35:39] DEBUG[909] res_http_websocket.c: Writing websocket string of length 749
[2017-01-15 18:35:39] DEBUG[978] channel.c: *TMP* Received ast_queue_hangup_with_cause for Local/13051002000-18001002000 at cont-fas-00000005;2
[2017-01-15 18:35:39] DEBUG[909] res_http_websocket.c: Writing websocket text frame, length 749
[2017-01-15 18:35:39] DEBUG[978] channel.c: *TMP* ast_queue_hangup_with_cause returning 0 for Local/13051002000-18001002000 at cont-fas-00000005;2
[2017-01-15 18:35:39] DEBUG[978] core_local.c: *TMP* No_res
*[2017-01-15 18:35:39] DEBUG[979][C-00000005] res_rtp_asterisk.c: No remote address on RTP instance '0x7f862c03c310' so dropping frame*
[...]
[2017-01-15 18:35:40] VERBOSE[979][C-00000005] app_dial.c: PJSIP/flowroute-00000005 is making progress passing it to Local/13051002000-18001002000 at cont-fas-00000005;2

+Observations+

* First of all, the flow through hangup functions is identical. P_CHAN_IF_2 means both cases call the ast_queue_hangup_with_cause(p->chan, cause) function inside ast_unreal_hangup.
* In both cases, ast_queue_hangup_with_cause returns 0 for the ;2 channels, which means the issue arises +after+ the ;2 hangup has been sheduled.
* Every time the problem manifests itself, there is this pesky "res_rtp_asterisk.c: No remote address on RTP instance" error, which does not appear in successful hangups. Maybe it's related? Could an RTP issue prevent a channel from hanging up properly?
* In both calls, the ;2 channels go through the same "Don't queue anything" case inside __ast_queue_frame.


was (Author: tompaw):
*UPDATE*: I have started digging in core_unreal and core_local. Here are my findings:

+Proper hangup+

[2017-01-15 18:35:16] DEBUG[963] core_local.c: *TMP* Entering local_hangup
[2017-01-15 18:35:16] DEBUG[963] core_unreal.c: *TMP* ast_unreal_lock_all(Local/13051002000-18001002000 at cont-fas-00000004;1) -> owner: Local/13051002000-18001002000 at cont-fas-00000004;1, chan: Local/13051002000-18001002000 at cont-fas-00000004;2
[2017-01-15 18:35:16] DEBUG[963] core_unreal.c: *TMP* Inside unreal_hangup(Local/13051002000-18001002000 at cont-fas-00000004;1) P_CHAN_IF_2
[2017-01-15 18:35:16] DEBUG[963] channel.c: *TMP* Received ast_queue_hangup_with_cause for Local/13051002000-18001002000 at cont-fas-00000004;2
[2017-01-15 18:35:16] DEBUG[963] channel.c: *TMP* ast_queue_hangup_with_cause returning 0 for Local/13051002000-18001002000 at cont-fas-00000004;2
[2017-01-15 18:35:16] DEBUG[963] core_local.c: *TMP* No_res
[2017-01-15 18:35:16] DEBUG[909] res_http_websocket.c: Writing websocket string of length 648
[2017-01-15 18:35:16] DEBUG[909] res_http_websocket.c: Writing websocket text frame, length 648
[2017-01-15 18:35:16] DEBUG[964][C-00000004] channel.c: Hanging up channel 'PJSIP/flowroute-00000003'
[2017-01-15 18:35:16] DEBUG[964][C-00000004] chan_pjsip.c: AST hangup cause 0 (no match found in PJSIP)
[2017-01-15 18:35:16] DEBUG[964][C-00000004] app_dial.c: Exiting with DIALSTATUS=CANCEL.
[2017-01-15 18:35:16] DEBUG[909] res_http_websocket.c: Writing websocket string of length 704
[2017-01-15 18:35:16] DEBUG[909] res_http_websocket.c: Writing websocket text frame, length 704
[2017-01-15 18:35:16] DEBUG[964][C-00000004] pbx.c: Spawn extension (cont-fas,13051002000-18001002000,5) exited non-zero on 'Local/13051002000-18001002000 at cont-fas-00000004;2'
[2017-01-15 18:35:16] DEBUG[859] devicestate.c: Changing state for Local/13051002000-18001002000 at cont-fas - state 1 (Not in use)
[2017-01-15 18:35:16] VERBOSE[964][C-00000004] pbx.c: Spawn extension (cont-fas, 13051002000-18001002000, 5) exited non-zero on 'Local/13051002000-18001002000 at cont-fas-00000004;2'
[2017-01-15 18:35:16] DEBUG[964][C-00000004] channel.c: Soft-Hanging (0x10) up channel 'Local/13051002000-18001002000 at cont-fas-00000004;2'
[2017-01-15 18:35:16] DEBUG[875] res_pjsip_session.c: Method is CANCEL
[2017-01-15 18:35:16] DEBUG[964][C-00000004] channel.c: Hanging up channel 'Local/13051002000-18001002000 at cont-fas-00000004;2'
[2017-01-15 18:35:16] DEBUG[875] res_config_pgsql.c: PostgreSQL query attempt 1
[2017-01-15 18:35:16] DEBUG[964][C-00000004] core_local.c: *TMP* Entering local_hangup
[2017-01-15 18:35:16] DEBUG[964][C-00000004] core_unreal.c: *TMP* ast_unreal_lock_all(Local/13051002000-18001002000 at cont-fas-00000004;2) -> owner: NULL, chan: Local/13051002000-18001002000 at cont-fas-00000004;2
[2017-01-15 18:35:16] DEBUG[964][C-00000004] core_local.c: *TMP* No_res
[2017-01-15 18:35:16] DEBUG[964][C-00000004] core_local.c: *TMP* Unlink_locals

+Zombie hangup+

[2017-01-15 18:35:39] DEBUG[978] channel.c: Hanging up channel 'Local/13051002000-18001002000 at cont-fas-00000005;1'
[2017-01-15 18:35:39] DEBUG[978] core_local.c: *TMP* Entering local_hangup
[2017-01-15 18:35:39] DEBUG[978] core_unreal.c: *TMP* ast_unreal_lock_all(Local/13051002000-18001002000 at cont-fas-00000005;1) -> owner: Local/13051002000-18001002000 at cont-fas-00000005;1, chan: Local/13051002000-18001002000 at cont-fas-00000005;2
[2017-01-15 18:35:39] DEBUG[978] core_unreal.c: *TMP* Inside unreal_hangup(Local/13051002000-18001002000 at cont-fas-00000005;1) P_CHAN_IF_2
[2017-01-15 18:35:39] DEBUG[909] res_http_websocket.c: Writing websocket string of length 749
[2017-01-15 18:35:39] DEBUG[978] channel.c: *TMP* Received ast_queue_hangup_with_cause for Local/13051002000-18001002000 at cont-fas-00000005;2
[2017-01-15 18:35:39] DEBUG[909] res_http_websocket.c: Writing websocket text frame, length 749
[2017-01-15 18:35:39] DEBUG[978] channel.c: *TMP* ast_queue_hangup_with_cause returning 0 for Local/13051002000-18001002000 at cont-fas-00000005;2
[2017-01-15 18:35:39] DEBUG[978] core_local.c: *TMP* No_res
*[2017-01-15 18:35:39] DEBUG[979][C-00000005] res_rtp_asterisk.c: No remote address on RTP instance '0x7f862c03c310' so dropping frame*
[...]
[2017-01-15 18:35:40] VERBOSE[979][C-00000005] app_dial.c: PJSIP/flowroute-00000005 is making progress passing it to Local/13051002000-18001002000 at cont-fas-00000005;2

+Observations+

* First of all, the flow through hangup functions is identical. P_CHAN_IF_2 means both cases call the ast_queue_hangup_with_cause(p->chan, cause) function inside ast_unreal_hangup.
* In both cases, ast_queue_hangup_with_cause returns 0 for the ;2 channels, which means the issue arises +after+ the ;2 hangup has been sheduled.
* Every time the problem manifests itself, there is this pesky "res_rtp_asterisk.c: No remote address on RTP instance" error, which does not appear in successful hangups. Maybe it's related? Could an RTP issue prevent a channel from hanging up properly?

> Channels with pre-dial handlers cannot be hung up via ARI
> ---------------------------------------------------------
>
>                 Key: ASTERISK-26716
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-26716
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Applications/app_stasis
>    Affects Versions: 13.13.1
>         Environment: - platform independent -
>            Reporter: Tom Pawelek
>            Assignee: Unassigned
>
> A local channel with a pre-dial handler will fail to be properly hung up in 90% of the cases - Asterisk does not send BYE/CANCEL on .hangup()
> ; Original channel
> {noformat}
> ch = client.channels.originate(endpoint="Local/12345 at cont-test", app="ari-test")
> {noformat}
> ; Dialplan
> {noformat}
> [test-handler]
> exten => testcall,1,NoOp(foo)
> exten => testcall,n,Return()
> [cont-test]
> exten => _XXX.,1,Answer()
> exten => _XXX.,n,Dial(PJSIP/bar at pstn,,b(test-handler^testcall^1(foo)))
> {noformat}
> ; Attempt to hang up
> {noformat}
> client.channels.hangup(channelId=ch_id)
> {noformat}
> Only b( ) handlers cause the issue to appear, B( ) works perfectly fine.



--
This message was sent by Atlassian JIRA
(v6.2#6252)

More information about the asterisk-bugs mailing list