[Home]

Summary:ASTERISK-28273: H245 logical channels don't close when asterisk is terminated the call.
Reporter:Dimos (dtrich0)Labels:patch
Date Opened:2019-02-05 04:41:15.000-0600Date Closed:
Priority:MajorRegression?
Status:Waiting for Feedback/In ProgressComponents:Addons/chan_ooh323
Versions:13.19.0 Frequency of
Occurrence		Constant
Related
Issues:
Environment:Debian Attachments:( 0) alcatel_asterisk_patch3.png
( 1) alcatel_ends_call.png
( 2) alcatel_terminating_call.txt
( 3) alcatelToAsteriskCallRequest.jpeg
( 4) alcatelToAsteriskCallRequest.txt
( 5) asterisk_console_patch5.txt
( 6) asterisk_ends_call_2.jpeg
( 7) asterisk_ends_call.png
( 8) asterisk_terminating_call.txt
( 9) ASTERISK-28273-1.patch
(10) ASTERISK-28273-2.patch
(11) ASTERISK-28273-3.patch
(12) ASTERISK-28273-4.patch
(13) ASTERISK-28273-5.patch
(14) ASTERISK-28273-6.patch
(15) ASTERISK-28273-7.patch
(16) Astrisk-Alcatel_afterPaching.txt
(17) call_with_patch2.png
(18) Cap_exchange_remaining.log
(19) endSessionCommandAFTERreleaseComplete.png
(20) endSessionCommandBEFOREreleaseComplete.png
(21) full
(22) full_patch5
(23) full28052019
(24) h323_log
(25) H323_log_28052019
(26) H323_log_patch3.txt
(27) h323_log_patch5
(28) ok.png
(29) OLCrejected.jpeg
(30) OLCrejected.PNG
(31) ooh323_log-call_with_patch2.txt
(32) prompt1.txt
(33) RTPpacketsAfterCallCompleted_.jpg
Description:There is a H323 trunk between asterisk and Alcatel pbx. When asterisk terminates the call, it does not send H245 closeLogicalChannel  request for the opened logical channels but only sends H245 EndSessionCommand. So, the Alcatel pbx keeps the H245 logical channels active in conference room and  that makes zombie/stucked channels. When Alcatel pbx ends the call there is no problem.
Comments:By: Asterisk Team (asteriskteam) 2019-02-05 04:41:16.711-0600

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.

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.
By: Dimos (dtrich0) 2019-02-05 04:46:01.294-0600

H323_log for calls when asterisk and alcatel pbxs terminated the call. Also the Wireshark's Voip flow sequence report for these calls.
By: George Joseph (gjoseph) 2019-02-05 07:43:36.707-0600

This module is supported by community member [~may213] and has been assigned to him for further action.


By: Alexander Anikin (may213) 2019-02-19 05:42:03.647-0600

Hello,
I will check the issue on my labs.

By: Alexander Anikin (may213) 2019-03-17 06:48:17.781-0500

Hello,

Please check the issue with attached patch.
it should send h.245 close logical channels and end session when call close from asterisk side.

By: Dimos (dtrich0) 2019-03-20 05:40:52.300-0500

Hi there,
Thanks for your reply.
I patched the source code and install&load the chan_ooh323.so module successfully but as you can see from Wireshark's Voip flow sequence report no result(see attached asterisk_ends_call_2.jpeg). In h323_log(see attached Astrisk-Alcatel_afterPaching.txt) I can see that you construct a closeLogicalChannel message but I can not see it in wireshark. Also it will be better asterisk to wait  for ack messages from Alcatel pbx and if timeout retransmit the closeLogicalChannel request  before to proceed ( ack the close of the H245 logical channel(s) and then close the session, etc. Please see the alcatel_ends_call.png). Many thanks again...

By: Dimos (dtrich0) 2019-03-20 05:42:24.742-0500

Call flow and h323_log after paching
By: Alexander Anikin (may213) 2019-03-27 16:46:45.537-0500

Hi

Please check the issue with second patch attached. There is loop to wait close LCs introduced.
CloseLCACK timer was implemented already but he activate on sending H.245 packet instead of queueing.
And these packets send directly now.
By: Dimos (dtrich0) 2019-03-29 08:42:09.825-0500

Hi Alexander,
Thanks for the second patch.
A clarification please, the second patch should be applied to the code already patched with ASTERISK-28273-1.patch or to the original code coming with asterisk-13.19.0 (asterisk-13-current.tar.gz)?
Thanks again.
By: Alexander Anikin (may213) 2019-03-29 15:39:11.364-0500

Hi
Second patch is applied to clean asterisk source without previous.

By: Dimos (dtrich0) 2019-04-01 09:19:38.652-0500

Hi again,
As you can see from the call_with_patch2.png and ooh323_log-call_with_patch2.txt during "Clearing all logical channels" you "Opening logical channels" without reason.
Could you fix it please?
By: Alexander Anikin (may213) 2019-04-10 17:41:58.905-0500

Hi Dimos,

Are you sure that you have patched with second patch in your latest test?
There is strange history:

16:47:43:394  In ooEndCall call state is - OO_CALL_CLEAR (outgoing, ooh323c_o_2)
...
16:47:43:405  CloseLogicalChannelAck received for 1001 (outgoing, ooh323c_o_2)
16:47:43:405  Deleted CloseLogicalChannel Timer. (outgoing, ooh323c_o_2)
16:47:43:405  Closing logical channel 1001 (outgoing, ooh323c_o_2)
16:47:43:405  Clearing logical channel number 1001. (outgoing, ooh323c_o_2)
16:47:43:405  Removed logical channel 1001 (outgoing, ooh323c_o_2)
16:47:43:405  Listing logical channel 25684 cap 2 state 3 for (outgoing, ooh323c_o_2)
16:47:43:405  Opening logical channels (outgoing, ooh323c_o_2)

where second patch contain:

int ooOpenLogicalChannels(OOH323CallData *call)
{
  int ret=0;

  if (call->callState >= OO_CALL_CLEAR) {
       OOTRACEINFO3("Not open logical channels on closing call(%s, %s)\n", call->callType,
                call->callToken);
       return OO_OK;

  }
  OOTRACEINFO3("Opening logical channels (%s, %s)\n", call->callType,
                call->callToken);


Logical channels opening could be happen if callState < OO_CALL_CLEAR only according this.

By: Alexander Anikin (may213) 2019-04-10 17:46:04.514-0500

Additionally I have few changed second patch and attach third here.
It also should be applied to clean asterisk source. Please test the issue again with 3rd patch.

By: Dimos (dtrich0) 2019-04-15 09:23:32.010-0500

Hi again,
Thanks for the third one.
I have downloaded the new asterisk version 13.26.0 source. I applied the ASTERISK-28273-3.patch successfully. The asterisk also has built and installed without error(see prompt1.txt). But when I start the service in full log I get the error: " ERROR[25276] chan_ooh323.c: OOH323 Listener Creation failure. OOH323 DISABLED" only and when I try to load chan_ooh323 from asterisk cli I get the message:
Chania-Comms*CLI> module load chan_ooh323.so
Unable to load module chan_ooh323.so
Command 'module load chan_ooh323.so' failed.
   --   == Setting default context to from-trunk
[Apr 15 16:56:52] WARNING[25608]: channel.c:569 ast_channel_register: Already have a handler for type 'OOH323'
[Apr 15 16:56:52] ERROR[25608]: chan_ooh323.c:3848 load_module: Unable to register channel class OOH323
Please advice
By: Alexander Anikin (may213) 2019-04-17 17:42:55.500-0500

Hi

I guess listener creation error haven't relation to the issue subject.
Could you please check /var/log/asterisk/h323_log after asterisk start. I hope it contain related error info. This like to someone already listen on 1720 or you changed listener port in your config.

By: Dimos (dtrich0) 2019-04-18 08:17:01.034-0500

You are correct!!!
I have set up a test server and I have copied the ooh323.conf from the productive one. So, I forget to change  the IP address asterisk is listening on for incoming H323 connections in the test server.
Sorry for the mess....I'll be back with the test results with the Alcatel pbx soon...
Sorry again...
By: Dimos (dtrich0) 2019-04-19 19:10:11.476-0500

I have tested the issue with 3rd patch and now everything looks ok (see ok.png file).
Thanks for your help :-)
By: Asterisk Team (asteriskteam) 2019-04-22 02:49:37.561-0500

This issue has been reopened as a result of your commenting on it as the reporter. It will be triaged once again as applicable.
By: Dimos (dtrich0) 2019-04-22 02:59:33.788-0500

Hi again,
I would like to reopen the issue as I observe that when the alcatel try to start a call after master-slave determination it is not opening any logical channel and both users do not hear any sound(see alcatelToAsteriskCallRequest.jpeg and alcatelToAsteriskCallRequest.txt). Also, some times asterisk asks to open new logical channel even if the call has finished(endSessionCommand from remote party). Please see "alcatel_asterisk_patch3.png" and "H323_log_patch3.txt"
Many thanks
By: Alexander Anikin (may213) 2019-04-22 18:52:08.936-0500

Hi

I have uploaded 4th patch, it should applied to clean asterisk sources as usually, please test it.

The issue with LCs have not opened fixed (it was introduced in previous patches here).

Reopening LCs by on CloseLCACK received was removed, I'm not sure if it is fully correct but should help here.  I think another cases where LCs need to reopen comes with TermCap exchange process, so we could remove reopen LCs here.

By: Dimos (dtrich0) 2019-04-24 03:41:54.032-0500

Hi again,
Yes I confirm that the issue with LCs have not opened it was introduced in previous patches(maybe starts from the second patch) here.
I have patched with the 4th one and the only issues that I have are the following:
1) When Asterisk ends the call the H245 ESC comes after H225 ReleaseComplete. Must be opposite(see endSessionCommandBEFOREreleaseComplete.png and endSessionCommandAFTERreleaseComplete.png.
2) Some times if the call has been terminated by the remote pbx and the asterisk user has not hung-up there is RTP packets from asterisk to remote pbx until chan_ooh323 detects lack of RTP packet from remote pbx :"NOTICE[1248]: chan_ooh323.c:4037 do_monitor: Disconnecting call 'OOH323/LOC-2' for lack of RTP activity in 61 seconds". Looks like for some reason even if the asterisk has close the H245 logical channel and H225 session it is continuing to transmit data to remote pbx.
I think both issues took place before the patches and work here.
I'll keep the system under monitoring for the next days to see if something else comes up and I keep you inform.
Thanks for the help :-)
By: Alexander Anikin (may213) 2019-04-24 04:36:06.900-0500

Hi

First case is possibile, I will check it.
Second case is strange, if remote pbx close call it should send ESC and ReleaseComplete and asterisk should close call by that.

Could you please attach h323_log for both cases, it will help to understand how to solve.

By: Dimos (dtrich0) 2019-04-24 07:10:54.279-0500

Hi again,
I have uploaded full and h323_log files. RTPpacketsAfterCallCompleted_.jpg from wireshark shows the problem with the RTP packets.
If you need something else please don't hesitate to ask it.
By: Alexander Anikin (may213) 2019-04-24 18:28:29.002-0500

Hi,

attached new patch, applied as usually.

ESC/ReleaseComplete wrong order should be fixed by flushing h225/h245 packet queues on such packet sending.

Non closed asterisk channel issue could be fixed also, but I'm not sure exactly.
If this issue still found please attach asterisk full log with verbosity level 3 at least  by 'core set verbose 3' and h323 debugging enabled by 'h323 set debug'

By: Dimos (dtrich0) 2019-04-25 05:42:06.034-0500

Hi again,
During test with patch4 I mentioned some calls "Not opening logical channels as Cap exchange remaining" (please see Cap_exchange_remaining.log). Could you check it please?
Unfortunately, I'll be out of office until Tuesday. So, I'll return to you next week with test results for patch5.
Many thanks :-)

By: Dimos (dtrich0) 2019-04-30 08:38:00.079-0500

Hi again,
I've tested the patch5 and the asterisk service crash after the call.In /var/log/syslog I got the message:
Apr 30 16:13:40 Chania-Comms kernel: [542807.584056] asterisk[26174]: segfault at 8 ip 00007fc19b8b1df4 sp 00007fc192d54b90 error 4 in chan_ooh323.so[7fc19b888000+13b000]
Attached and the full_patch5, h323_log_patch5 and asterisk console output(asterisk_console_patch5.txt).
By: Alexander Anikin (may213) 2019-05-27 06:06:27.408-0500

Hi
Sorry for long silence. It was heavy work on another projects and vacation thereafter.
New more complex patch have prepared in ASTERISK-28273-6.patch. This have changed logical channels processed logic,
now it depend of Fast Start is active or not. Tested in my labs and have success results with different configs.
Please make your tests with it.
By: Alexander Anikin (may213) 2019-05-27 06:08:22.673-0500

As usually the patch should be applied to clean asterisk source.

By: Dimos (dtrich0) 2019-06-03 05:23:45.496-0500

Hi again and thanks for the patch.
The hand-shake is working properly but some times the asterisk's OLC request  gets sessionID 0 that is not a appropriate number and the Alcatel pbx rejects the connection. See the OLCrejected.jpeg and OLCrejected.png. Attached and the full28052019 and H323_log_28052019 log files.
Many thanks.
By: Alexander Anikin (may213) 2019-06-04 07:22:13.738-0500

Hi

Uploaded new patch ([^ASTERISK-28273-7.patch]), please try with him.

New things are there:

remove delay between closing LCs and EndSession sending.

remove sessionID = 0 for opposites with H.245 version <= 8
(when we are slave with MSD, we could ask sessionID from master side by setting it to zero, seems like many switches report this as error, i guess they have lower H.245 version). SessionID is 1/2/3 for audio/video/data channels for that cases.

remove inital opening transmit LC when we are slave with MSD. If we are slave our transmit LC will opened after receive LC will established. This change avoid simultaneous opening LCs from both sides with same number.