Summary:	ASTERISK-07591: Calls from Asterisk to some H.323 ATAs ring but don't complete
Reporter:	Juan Carlos Castro y Castro (jccyc)	Labels:
Date Opened:	2006-08-23 16:56:17	Date Closed:	2011-06-07 14:03:05
Priority:	Major	Regression?	No
Status:	Closed/Complete	Components:	Channels/General
Versions:		Frequency of Occurrence
Related Issues:
Environment:		Attachments:	( 0) asterisk-on-my-lab-to-ata.png ( 1) h323_log ( 2) h323_log_2 ( 3) ooCapability.c ( 4) ooLogChan.c
Description:	I have the following problem: I have an Asterisk+GnuGK installation, in which the brand of H.323 ATAs we use (obscure OEM; I believe the maker is Aristel) are unable to receive calls. The phone rings, when I pick it up it's all mute and - that's the weird part - the originator keeps on hearing ring tones as if nobody had picked up. When the receiving (mute) end hangs up, the call is terminated. Calls in the other direction don't have this problem. It's not an obvious ATA bug, neither a GnuGK bug -- two ATAs can call each other just fine. More: Asterisk can call an H.323 softphone (SJPhone) fine too. The traffic from the latter looks mighty different from that from a call to an ATA. Here's links to Ethereal analyses of three cases: Asterisk to SJPhone (OK): http://img78.imageshack.us/img78/9452/asterisktosoftphoneka1.png Asterisk to ATA (Rings but doesn't complete): http://img78.imageshack.us/img78/8003/asterisktoatasq5.png ATA to ATA (OK): http://img168.imageshack.us/img168/1830/atatoouratajd6.png The big difference between Asterisk-to-ATA and ATA-to-ATA is, Asterisk (or, rather, chan_ooh323) never sends terminalCapabilitySet or masterSlaveDetermination packets. And, of course, there's no RTP coming from Asterisk. All captures were made at the gatekeeper. It has two IP addresses (has to because of Linux-HA). Switching to it having only one IP didn't help. Yes, I have the .cap files that originated those. They're rather big. I can provide them on a case-by-case basis. I fear there will have to be some hacking in chan_ooh323 (hence me posting here) in order for it to speak properly with the ATAs like other ATAs do. If someone would like to test this, I can register my H.323 ATA with the gatekeeper you're using, and keep on making and receiving calls at your leisure. Plus chatting via MSN or the messenger of your choice, or IRC. ****** ADDITIONAL INFORMATION ****** Here's my gnugk.ini, with some information edited out for privacy reasons: ------------------------------------------------------------ [Gatekeeper::Main] Fourtytwo=42 Name=OpenH323GK TimeToLive=120 [RoutedMode] GKRouted=1 H245Routed=1 CallSignalPort=1720 SupportNATedEndpoints=1 AcceptNeighborsCalls=1 RemoveH245AddressOnTunneling=1 [Proxy] Enable=1 RTPPortRange=1721-3000 ProxyForNAT=1 [RoutingPolicy] default=internal [RasSrv::GWPrefixes] <h323id-of-first-asterisk>=* <h323id-of-first-asterisk>=* [RasSrv::ARQFeatures] RoundRobinGateways=1 [Gatekeeper::Auth] FileIPAuth=optional;RRQ SQLAuth=sufficient;RRQ [FileIPAuth] <my-ip-range>=allow ------------------------------------------------------------ And my ooh323.conf, likewise edited: ------------------------------------------------------------ [general] port=1720 bindaddr=<ip-of-this-asterisk> gateway=yes faststart=yes h245tunneling=yes h323id=<hostname-of-this-asterisk> e164=<some-unique-number-i-assigned> gatekeeper=<ip-of-my-gnugk> logfile=/var/log/asterisk/h323_log context=<my-context> accountcode=<my-account-code> allow=g729 allow=gsm allow=ulaw dtmfmode=rfc2833 ------------------------------------------------------------
Comments:	By: Serge Vecher (serge-v) 2006-08-24 08:24:15 since you are using Asterisk 1.2.10, I assume you are using addons 1.2.3 Could you please check-out Asterisk 1.2.11 and addons 1.2.4? There were quite a few fixes to chan-ooh323 in that release. Also, you may also check how the native chan-h323 behaves in this situation (see bug 7705 for the developer branch that has the channel working with current trunk). Thanks and please report the results. By: Juan Carlos Castro y Castro (jccyc) 2006-08-24 08:44:22 Updated and repeated the test, same thing happened. With chan-h323, I get an ultra-short ring and the call fails. Maybe it's just a configuration issue, but this is not a solution for us because it can't register itself with a gatekeeper as a Gateway, only as a Terminal. Look at what Vlasis Hatzistavrou had to say in asterisk-dev: "I believe that this is related to a known bug of chan_ooh323 where Asterisk does not respond/handle properly the CONNECT message it receives from the far end." I found no bugs here resembling that. By: Paul Cadach (pcadach) 2006-08-24 09:00:41 JCCyC: Please, move discussion about operation of chan_h323-live branch to ASTERISK-7509. I'll glad to help you configure chan_h323 to work with GK as gateway and solve problems with dropped calls if you able to provide debugging/call tracing information. By: Objective Systems (objsys) 2006-08-24 09:14:36 "I believe that this is related to a known bug of chan_ooh323 where Asterisk does not respond/handle properly the CONNECT message it receives from the far end." There has been change added in asterisk-addons 1.2 branch to reply fast start in ALERTING message. This was known problem. Use the branch code to check you still face this problem? svn checkout http://svn.digium.com/svn/asterisk-addons/branches/1.2 asterisk-addons-1.2 If fast start is used and RTP is setup, than terminalSetupCap and masterSlaveDetermination is not required. I will check the logs you have uploaded, meanwhile let me know the result for testing with 1.2 branch code. Regards, Avin Patel Objective Systems Inc By: Objective Systems (objsys) 2006-08-24 09:33:13 Hi, You will have to provide me debug logs for the case Asterisk-ATA. Steps to update: ---------------- Please download the fresh copy from the svn 1.2 branch. svn checkout http://svn.digium.com/svn/asterisk-addons/branches/1.2 asterisk-addons-1.2 Please provide output of following command cd asterisk-addons-1.2 svn update svn info Steps to provide debug logs: --------------------------- Procedure to create debug log is: cd asterisk-addons-1.2/asterisk-ooh323c make clean make debug su make install Run the asterisk with -vvvc option. Than post here the /var/log/asterisk/h323_log /var/log/asterisk/messages And any message printed on CLI prompt Hopefully we will be able to solve this problem now. Regards, Avin Patel Objective Systems Inc By: Juan Carlos Castro y Castro (jccyc) 2006-08-24 09:39:52 Will do, stay tuned. Thanks! By: Juan Carlos Castro y Castro (jccyc) 2006-08-24 09:42:23 Getting branch: [root@iv-imp-00 jcastro]# cd asterisk-addons-1.2/ [root@iv-imp-00 asterisk-addons-1.2]# svn update At revision 282. [root@iv-imp-00 asterisk-addons-1.2]# svn info Path: . URL: http://svn.digium.com/svn/asterisk-addons/branches/1.2 Repository UUID: bbbafe65-6c06-0410-a0a5-c710d232821c Revision: 282 Node Kind: directory Schedule: normal Last Changed Author: objsys Last Changed Rev: 273 Last Changed Date: 2006-08-08 12:35:46 -0300 (Tue, 08 Aug 2006) Properties Last Updated: 2006-08-24 11:41:35 -0300 (Thu, 24 Aug 2006) By: Juan Carlos Castro y Castro (jccyc) 2006-08-24 09:50:11 Same problem. Here's the CLI output of the Dial. Gonna get the other logs...    -- Executing Dial("SIP/1001-0845fb98", "OOH323/1002") in new stack    -- Called 1002    -- SIP Seeding peer from astdb: '1001' at 1001@200.184.189.131:5060 for 600 Aug 24 11:46:58 DEBUG[5569]: chan_sip.c:11109 handle_request: That's odd...  Got a response on a call we dont know about. Cseq 102 Cmd SIP/2.0 Aug 24 11:46:58 DEBUG[5553]: channel.c:777 channel_find_locked: Avoiding initial deadlock for 'OOH323/1002-d116'    -- OOH323/1002-d116 is ringing    -- Remote UNIX connection  == Everyone is busy/congested at this time (1:0/0/1) Aug 24 11:47:12 DEBUG[5704]: app_dial.c:1628 dial_exec_full: Exiting with DIALSTATUS=CHANUNAVAIL. Aug 24 11:47:12 DEBUG[5704]: pbx.c:1589 pbx_substitute_variables_helper_full: Expression result is '0' By: Juan Carlos Castro y Castro (jccyc) 2006-08-24 09:58:42 In my logger.conf, I get everything in console, as well as in the debug file. Those messages were all that was output. Next I'll upload h323_log. By: Objective Systems (objsys) 2006-08-24 10:08:52 Hi JCCyC, In h323_log, I don't see any setup request is send. You will have to run the call from Asterisk->ATA as for second image, complete the call, than post the h323_log. Regards, Avin Patel By: Juan Carlos Castro y Castro (jccyc) 2006-08-24 10:36:35 ??? I did the same thing. I made a call from Asterisk to the ATA, the ATA ringed, picked it up, no sound, kept on ringing at originator. The only difference is, I couldn't keep on testing on the client so I moved the setup to our own machines. That, and I was using this new chan_ooh323. Now even this machine has other things running too, so I'll have to set up Asterisk on another machine. This will take a while. And when I call, I'll capture packets in addition to making those logs. By: Juan Carlos Castro y Castro (jccyc) 2006-08-24 11:33:23 Now, when I try to load chan_ooh323.so on the new machine, I get "Unable to load module chan_ooh323.so". This happens even with the stable version so it has to be something stupid on my part, I guess. But what? By: Objective Systems (objsys) 2006-08-24 11:43:32 I hope you did as follow: cd asterisk-addons-1.2/asterisk-ooh323c make clean make debug su make install And using asterisk-1.2.xx, Not asterisk trunk branch. By: Juan Carlos Castro y Castro (jccyc) 2006-08-24 11:51:35 That's correct. And yes, it was something idiotic -- I hadn't defined in extensions.ael2 the default context set in ooh323.conf. Almost everything set up now. Just a few minutes... By: Juan Carlos Castro y Castro (jccyc) 2006-08-24 14:04:52 Here's the log from the new attempt. h323_log coming shortly, and this time I have a packet capture too.    -- Executing Dial("SIP/1001-08abf190", "OOH323/1002") in new stack    -- Called 1002    -- SIP Seeding peer from astdb: '1001' at 1001@200.184.189.131:5060 for 600    -- OOH323/1002-2363 is ringing Aug 24 16:02:13 DEBUG[10691]: chan_sip.c:11130 handle_request: That's odd...  Got a response on a call we dont know about. Cseq 102 Cmd SIP/2.0Aug 24 16:02:18 DEBUG[10692]: res_config_odbc.c:124 realtime_odbc: ODBC SQL Param = '4569' Aug 24 16:02:18 DEBUG[10692]: res_config_odbc.c:124 realtime_odbc: ODBC SQL Param = '70.87.18.51' Aug 24 16:02:18 DEBUG[10692]: res_config_odbc.c:124 realtime_odbc: ODBC SQL Param = '4569' Aug 24 16:02:18 DEBUG[10692]: res_config_odbc.c:124 realtime_odbc: ODBC SQL Param = '70.87.18.35'  == Everyone is busy/congested at this time (1:0/0/1) Aug 24 16:02:24 DEBUG[10701]: app_dial.c:1635 dial_exec_full: Exiting with DIALSTATUS=CHANUNAVAIL.  == Auto fallthrough, channel 'SIP/1001-08abf190' status is 'CHANUNAVAIL' By: Objective Systems (objsys) 2006-08-24 14:21:58 Hi JCCyC, Unbalanced Structure or Not able to match fast start channel. This happens with couple of devices. It will take little time, As I have to find the real problem behind not able to match the channel. This leads to uncertain behavior, like one side audio. You can help by looking at something wrong in ooFindLogicalChannel() Regards, Avin Patel Objective Systems Inc By: Juan Carlos Castro y Castro (jccyc) 2006-08-24 14:25:34 If you want me to help testing I can register my ATA on your server. By: Objective Systems (objsys) 2006-08-24 15:52:14 Not now, Logs is enough for now. By: Juan Carlos Castro y Castro (jccyc) 2006-08-24 17:05:09 I can also send you the .cap file of the last call (it's huge, lots of extraneous fluff in there) if you want to see exactly what bytes were in that packet. Or, I could explore the .cap file here and send you a dump of the particular packet(s) you want. By: Objective Systems (objsys) 2006-09-14 15:03:01 Hi JCCyC, I would need some more logs to find out, why channel comparing is failing. I have attached two files: ooLogChan.c, ooCapability.c Please replace it with files at asterisk-addons-1.2/asterisk-ooh323c/ooh323c/src. Than cd asterisk-addons-1.2/asterisk-ooh323c make debug su make install Run the asterisk with -vvvc option. Than run the same call again, & send me the /var/log/asterisk/h323_log. That should help. Regards, Avin Patel Objective Systems Inc By: Objective Systems (objsys) 2006-09-19 10:32:11 Hi JCCyC, Any update on this issue ASTERISK-7591? Are you able to solve this problem? Regards, Avin Patel By: Juan Carlos Castro y Castro (jccyc) 2006-09-19 15:57:08 Hi Avin. Right now I'm completely tied up in another project. I'll check with Paulo when will we be able to set up out testbed again. By: jmls (jmls) 2006-11-01 12:39:52.000-0600 JCCyC: any update on this ? By: Joshua C. Colp (jcolp) 2006-11-20 20:37:43.000-0600 Once you have the needed debug information and can lab this up please feel free to reopen this bug so Avin can work with you. Thanks!