Summary:	ASTERISK-02971: Timeout problem with CallerID via DTMF/Polarity on TDM400P
Reporter:	rickardk (rickardk)	Labels:
Date Opened:	2004-12-12 09:25:07.000-0600	Date Closed:	2005-04-05 05:01:21
Priority:	Minor	Regression?	No
Status:	Closed/Complete	Components:	Core/General
Versions:		Frequency of Occurrence
Related Issues:
Environment:		Attachments:	( 0) chan_zap.c_dtmf.txt ( 1) chan_zap.c.diff
Description:	Incorrect timeout value makes CallerID via DTMF/Polarity fail 9 times out of 10 on incoming calls from analogue line via TDM400P+FXO connected to main telco in Sweden. ****** ADDITIONAL INFORMATION ****** Variable 'res' is used for both timeout constant and result from wait in the same loop. The problem was resolved by setting a fixed timeout value.
Comments:	By: Olle Johansson (oej) 2004-12-12 15:41:03.000-0600 Is this patch disclaimed? By: Olle Johansson (oej) 2004-12-12 15:43:00.000-0600 Also, please add separate patch file, created with cvs diff -u, thank you. Read the bug guidelines before posting patches to make life more simple both for you and for us bug marshals. Tack så mycket! /O :-) By: Mark Spencer (markster) 2004-12-12 18:42:18.000-0600 The reason "res" is used for the timer is so that if DTMF is not received, we eventually give up on the wait.  Forcing it to 2000 means that it could stay in that loop indefinitely.  Does increasing the 2000 to a higher number (e.g. 4000) make a difference? By: egnarf (egnarf) 2004-12-13 02:54:17.000-0600 The swedish specs say that the ring-signal must be sent no later than 1sec after the end of CID, so 2sec should be more than enough provided that the polarity-reversal and DTMF is detected correctly. I'm also in sweden, and I wrote this particular piece of code. I'll try to upgrade to cvs head tonight and see if I get the same problem. Could you provide me with the full debug output during a call where cid failed and one where it was transmitted successfully? Feel free to email me at mrbk@gnarf.org for more "direct" contact. By: rickardk (rickardk) 2004-12-13 03:21:52.000-0600 I actually tried 4000, but it was still unstable with that. 10000 does work, but I thought it felt a bit long.. As you can see from the attached debug, all digits are received correctly. I think it's the polarity change after the last digit that makes it go wrong and enter the ast_waitfor with a to small number, so that's why I thought that a constant timeout of 2000 would be sufficient at all times. But it's your choice of course :-) By: egnarf (egnarf) 2004-12-13 03:30:49.000-0600 There seems to be something odd with the ring-detector. Looking at the debug-statement, look for the "Got event Ring/Answered" line. Look at the time at which it arrives, it is 8 seconds after the last digit was received. It should be less than 1 second. The secondary polarity-reversal is there to mark the end of CID, although we ignore it since we look for the ring-signal instead. The ring should be sent directly after the second polarity-reversal. So either the ring-detector is broken, or your telco is. You don't happen to have a multimeter? =) Ps. Just thought about something.. Do you have distinctive-ring detection enabled? If so, turn it off. It might be that the first ring-signal isn't delivered and we trigger on the second/third/etc instead. I don't know how the distinctive-ring detector works so I don't know if it could cause this. edited on: 12-13-04 03:32 By: rickardk (rickardk) 2004-12-13 06:31:36.000-0600 markster and egnarf, you're both right; We don't want to stay in an infinite loop, and the core problem seems to be the time between the last digit and the first ring. All digits are always received, so it's however a pity to discard the callerid just because the first ring is late. I agree that it looks like the telco is broken, and I assume that it could also be related to the hardware? I did a few more test now, and this time received the first ring after about 1850 ms. So today it would have worked, although with small marginals.. I would vote for a larger timer, as markster suggested; either configurable or large enough to handle most situations. 10000 seemed to work at all times, but I'm not sure if there are any drawbacks with such a large setting. By: egnarf (egnarf) 2004-12-13 07:03:13.000-0600 IF it is the telco then increasing the timeout is the only viable way. However, if it is a problem with the ring-detector then we should fix that. Do you have some way to test if it's the telco? You could check it with a multimeter, or connect another phone to the line and see if it rings about the same time that asterisk detects the ring-signal. The only drawback that I can think of with increasing the timeout is that the channel isn't freed until the timeout occurs if someone hangs up before being connected. I.e. someone calls you, then hangs up while the CID is being transmitted then we wait for the timeout to occur before releasing the channel. There is also the risk that someone else calls while we wait, and you get the wrong callerid. The best thing is probably to make it configurable. I'll try to add a patch when time permits. Feel free to add one yourself if you can't wait for me to get it done =) By: rickardk (rickardk) 2004-12-13 07:23:58.000-0600 You're right again.. It's not the telco. Asterisk does miss the first ring, which comes in at the same time as the Polarity Reversal is logged. Another strange thing is that if a new call comes in within around 20 seconds, the TDM400P will answer with a modem carrier(!). I've seen discussions on the lists about other problems with polarity reversal, so maybe this is related. By: egnarf (egnarf) 2004-12-13 07:56:00.000-0600 Hmm.. Odd. Well, I'll test with cvs head here as soon as I have free time for it. No promises though, since I'm a bit swamped right now. Maybe markster has some ideas? By: egnarf (egnarf) 2004-12-21 12:33:23.000-0600 Just tested with todays cvs head and I can't reproduce your problem. I get correct cid and correctly detected ring every time. Could you try with latest cvs and see if the problem has been remedied? And if not, have you changed anything in the zaptel-driver? What parameters do you use when loading the module? By: rickardk (rickardk) 2005-01-06 07:51:36.000-0600 Sorry for the delay. I'm running this on a production box with limited possibilities to shut down the service. I just tried again with the latest CVS, and both problems are still there; 1) first ring is not detected, resulting in a frequent timeout in DTMFCID detection, and 2) An incoming call within 20 secs after the previous call was hung up results in that the TDM400P card answers with a modem carrier tone. Are you using a TDM400P as well? This is not a major problem for me as 99% of the calls come in via SIP and I only have one single analog line on this box, so if I'm the only one having this problem it might not be worth spending more time on it... I've played around with the configs, but these are the current settings: zaptel.conf: fxsks=4 loadzone=se defaultzone=se zapata.conf: [channels] signalling=fxs_ks echocancel=yes echocancelwhenbridged=yes echotraining=400 immediate=yes usecallerid=yes cidsignalling=dtmf cidstart=polarity callerid=asreceived useincomingcalleridonzaptransfer=yes hanguponpolarityswitch=yes group=1 context=inbound-analog channel => 4 Rickard edited on: 01-06-05 07:55 By: egnarf (egnarf) 2005-01-06 08:06:11.000-0600 Your config is identical with mine, except that I have immediate=no You might want to try that, although I don't see why it would make a difference  in this case. Also, do you load wctdm with any parameters? My parameters are:  wctdm opermode=SWEDEN debug=1 By: Mark Spencer (markster) 2005-01-16 01:58:17.000-0600 immediate=yes could definitely change the behavior.  Did changing it to immediate=no eliminate your problem, rickardk? By: rickardk (rickardk) 2005-01-18 08:05:09.000-0600 Nope. Sorry..none of these parameters made any difference. By: Clod Patry (junky) 2005-02-27 22:00:05.000-0600 Where are we with this bug? Any development by someone? Are some people working on that? By: Olle Johansson (oej) 2005-03-17 08:08:29.000-0600 Hey fellow countrymen! Any response, updates or new comments on this bug report? /Olle By: rickardk (rickardk) 2005-03-17 08:24:40.000-0600 Hej Olle, The problem is minor for me, and since it seems not to be reproduceable by anyone else I assume we can close this for now..? Rickard By: Clod Patry (junky) 2005-03-28 02:52:05.000-0600 I'm closing it for now. Feel free to re-open it if you can duplicate it. Thanks.