Summary:	ASTERISK-29437: ARI / channel events: events emitted after ChannelDestroyed
Reporter:	Jean Aunis - Prescom (PrescomJA)	Labels:
Date Opened:	2021-05-20 04:45:53	Date Closed:	2021-05-20 07:18:34
Priority:	Major	Regression?
Status:	Closed/Complete	Components:	Resources/res_ari_channels
Versions:	16.16.0	Frequency of Occurrence	Occasional
Related Issues:
Environment:		Attachments:	( 0) events_outoforder.pcap ( 1) full.txt
Description:	It happens randomly that ChannelHangupRequest and StasisEnd events are emitted by Asterisk after the ChannelDestroyed event. As far as I understand, ChannelDestroyed should always be the last event emitted for a given channel, so ChannelHangupRequest and StasisEnd should be always emitted before. I'm attaching the full log and a wireshark capture of the ARI Websocket highlighting the issue: - a SIP call is received and cancelled after 2 seconds - when the CANCEL request is received, ARI events are emitted in this order : 1- ChannelDestroyed (packets 84 and 87) 2- ChannelHangupRequest (packet 91) 3- StasisEnd (packet 93)
Comments:	By: Asterisk Team (asteriskteam) 2021-05-20 04:45:54.727-0500 Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution. Please note that log messages and other files should not be sent to the Sangoma Asterisk Team unless explicitly asked for. All files should be placed on this issue in a sanitized fashion as needed. A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report. Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process]. Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur. Please note that by submitting data, code, or documentation to Sangoma through JIRA, you accept the Terms of Use present at [https://www.asterisk.org/terms-of-use/|https://www.asterisk.org/terms-of-use/]. By: Jean Aunis - Prescom (PrescomJA) 2021-05-20 04:47:02.686-0500 Please find attached the full log and the wireshark capture. By: Joshua C. Colp (jcolp) 2021-05-20 04:52:41.877-0500 The attached packet capture does not include any Websocket traffic. It includes SIP, HTTP requests, and some TCP level traffic. You'll also need to provide more information on how exactly you are using ARI and the subscriptions in place. For example in your packet capture I see you explicitly subscribing. Are you doing that alongside the channel being in the same application? Are there two applications involved? You could also do "ari set debug all on" in the Asterisk CLI to enable ARI debugging. By: Jean Aunis - Prescom (PrescomJA) 2021-05-20 05:18:59.848-0500 I didn't capture the Websocket handshake, so the traffic may not be properly displayed by wireshark, but events are visible in the payload of TCP packets (port 8088). The inbound channel is placed in the Stasis application "bridge-dial" by the dialplan. Another application called "noOp" subscribes to the channel. So there are 2 applications subscribed to the channel: "noOp" and "bridge-dial". In the logs the offending channel has the id 1621492709.539. Not much is done on it: the "noOp" application is subscribed and a few variables are retrieved. Unfortunately the issue is difficult to reproduce. I will provide ARI debugging if I can. By: Joshua C. Colp (jcolp) 2021-05-20 05:41:06.844-0500 Okay, the fact you have two applications would be why this is happening. Ordering is only guaranteed at an application level. 84 and 87 are published to "noOp" while 91 and 93 are published to "bridge-dial". There is no guarantee of ordering between the two applications. They could go out of order, they might not. By: Jean Aunis - Prescom (PrescomJA) 2021-05-20 07:03:47.921-0500 OK, got it. I thought the ordering was guaranteed on the channel regardless of the application. So that's not a bug. Thanks for the quick feedback.