[Home]

Summary:ASTERISK-16003: [patch] asterisk dsp always reports detected DTMF length to be 0ms
Reporter:frawd (frawd)Labels:
Date Opened:2010-04-23 10:21:15Date Closed:2010-05-21 04:32:05
Priority:TrivialRegression?No
Status:Closed/CompleteComponents:Core/General
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) 20100511__issue17235.diff.txt
( 1) 20100518__issue17235.diff.txt
( 2) dsp_dtmf_length_rev258772.diff
( 3) dtmf_dsp_len.patch
( 4) new_dtmf_dsp_len.patch
Description:The attached patch makes the DSP report the correct length for DTMF detected in the audio.

Tested with DAHDI channels (FXS, FXO, ISDN PRI) and SIP channels configured as "inband".

****** ADDITIONAL INFORMATION ******

[Apr 23 15:51:50] DTMF[10866]: channel.c:2918 __ast_read: DTMF begin '9' received on DAHDI/1-1
[Apr 23 15:51:50] DTMF[10866]: channel.c:2928 __ast_read: DTMF begin passthrough '9' on DAHDI/1-1
[Apr 23 15:51:50] DTMF[10866]: channel.c:2846 __ast_read: DTMF end '9' received on DAHDI/1-1, duration 0 ms
[Apr 23 15:51:50] DTMF[10866]: channel.c:2886 __ast_read: DTMF end accepted with begin '9' on DAHDI/1-1
[Apr 23 15:51:50] DTMF[10866]: channel.c:2902 __ast_read: DTMF end passthrough '9' on DAHDI/1-1
Comments:By: Paul Belanger (pabelanger) 2010-04-23 10:33:26

Thanks for the patch.  It might be a good idea to also submit it against trunk, even though I don't think there will be much difference.
By: frawd (frawd) 2010-04-23 17:52:13

There you go, against trunk rev258772.
By: Leif Madsen (lmadsen) 2010-04-26 12:52:22

Feel free to email the asterisk-dev and/or asterisk-users mailing lists to try and get some other people to test this and report back. Thanks!
By: Kaloyan Kovachev (knk) 2010-04-27 09:08:47

just an idea, why not reuse dtmf_began?
By: frawd (frawd) 2010-04-27 09:53:42

It depends what would be considered more optimized between:

- adding one more variable (dtmf_tv) in dsp struct, and initializing it only when necessary (when DSP_FEATURE_DIGIT_DETECT is set).
or
- reusing dtmf_began and having to initialize it to gettimeofday (ast_tvnow) even if not needed (when DSP_FEATURE_DIGIT_DETECT is unset).

I can upload a patch reusing dtmf_began if needed.
By: Russell Bryant (russell) 2010-04-27 12:26:40

What was the bug that you hit that caused you to find this and make this change?
By: Dmitry Andrianov (dimas) 2010-04-27 16:41:17

Strictly speaking, your patch just adds the length. It does not add "the correct length" as you write.

First of all this is because of current_digits buffer. If two DTMF digits are detected within single audio frame, they are buffered using this buffer. These will be unbuffered and returned during next calls to dsp_process and the time information from tv_now is meaningless in this case.

Like Russel I wonder what are you trying to fix because Asterisk should live ok with zero len DTMFs - it will emulate one of minimum length anyway.

I'm afraid that in order to provide correct length information dsp.c needs more serios changes than ones you suggested.
By: frawd (frawd) 2010-04-28 05:54:21

The initial issue happened when a device sending a series of short (~80ms) DTMF and hanging up immediately after the last digit. The last 2 or 3 digits were all detected correctly but never forwarded to the other channel.

The sequence of digits being detected as 0ms were all emulated, the next one being queued in ast_read. The hangup apparently forgets that queue with the last digit in.

I started reducing a bit the AST_MIN_DTMF_DURATION with no success, I also remove all inline features (xfer, ...) that were making things worse when setting some strange DEFER_DTMF flag (might also be an issue). While it made things better, the last DTMF was still stuck in that read queue on hangup and never forwarded.

I figured that the easiest way to prevent this would be if the dsp reported the digits length, to make ast_read pass it through and avoid queueing.

I agree it is an incorrect approach to calculate the digit's length, but the strange thing is that it looks like it works quite well in reporting the digit's length, probably because frame length is usually quite short and what you describe might not happen that often (not sure). But it actually resolves my issue (the last digit is now forwarded).

I will look into maybe counting the "hits" which apparently have a fixed size of 102 samples (DTMF_GSIZE). Would this be a correct approach or am I loosing my time?

Thanks again for your time and interest in that issue, sorry if I might have tried to push it too much.
By: Dmitry Andrianov (dimas) 2010-04-28 13:29:50

I think it is just coincidence that your patch fixes your problem. If caller hangs up _immediately_ after sending the last digit, there is always a good chance the last digit won't be properly relayed.  This is because even DTMF BEGIN frame is delayed a bit by dsp.c - until it gets reliable detection. So to me it looks like you should use some other approach to fix your issue.

The only way to properly report the duration is to modify functions doing digit detection so it will report not just digit but its start/end times as well.
By: frawd (frawd) 2010-04-28 13:49:28

"immediately" is around 50ms after the last digit.

I will try first to do a correct duration report in the dsp since it coincidently fixes my problem, it could be a start for me to learn something (it's also quite irritating to see those 0ms in debug mode).

I would like to avoid using ast_tvnow() every time I have some hit or miss in digit detection if possible. Is reporting the number of "hits" and multiplying that with the goertzel block duration really impossible?
By: Dmitry Andrianov (dimas) 2010-04-28 14:38:05

Well. If I wanted to do it in a proper way, it would require a lot of effort:
1. modify digit state structures to have _sample_ (not block) counter for the current digit.
2. modify dtmf_detect to properly initialize and increment this counter.
3. modify structure of dtmf queue to have duration information for queued digits.

I know this is too generic and devil is in details...
By: frawd (frawd) 2010-04-29 17:52:30

Thanks for the comments, would the attached patch be the right idea?

It's for 1.6.2, I quickly tested and it reports some length which I believe is a bit closer to reality compared to the last one.

If dtmf are detected by blocks of 102 samples, it means we will always have multiples of 12.75ms (rounded). I'm not sure if I can plug that in deeper than dtmf_detect (in goertzel functions?) somehow to improve the resolution to 1 sample as I understand you suggested. Are you sure it can be done?
By: frawd (frawd) 2010-05-04 05:00:58

So far so good, I have this in 2 production servers, it resolves my bug but the length is only multiples of 12.75ms. It's good enough for me.

This resolution could apparently be improved implementing some "sliding goertzel" algorithm. I could try that if you believe it is needed, the only thing is that it would represent a core change potentially affecting many users and I don't think it would ever be committed...
By: Tilghman Lesher (tilghman) 2010-05-11 17:54:17

I made some slight modifications to your patch, because it was still possible for 0-length DTMF_END frames to be sent out, due to the possibility of hits_to_begin being lower than misses_to_end.  If the new digit was detected at the end of a frame, but the old digit's misses were not sufficiently high enough to declare an end, then you could get a zero-length DTMF_END.  I consider that possibility a long shot, but it's worth avoiding, anyway.
By: frawd (frawd) 2010-05-17 03:54:28

Hello tilghman, sorry I cannot test trunk easily, but could you test it with your patch?

I have some doubt about your patch in that it would not work in the same situation you describe. The way I worked around this problem in my version was to store the digit's length on the very first miss, before storing any new digit. The bad thing I realize now is that I should ADD that length to the previously stored one in case the digit does not reach misses_to_end and restarts counting dtmf.hits (it is reset to 1 on the first miss so we must store it at that point).

In my patch the change would be in the "store_digit_samples" function:
- s->digits[s->current_digits - 1].samples = samples;
+ s->digits[s->current_digits - 1].samples += samples;


Even tho your patch is cleaner, you wait for the misses_to_end to be reached to store the digit's length, but the dtmf.hits variable is reset to '1' anyway on the first miss. It looks like it will always report 13ms (1 hit).

Am I wrong?
By: Tilghman Lesher (tilghman) 2010-05-18 14:13:12

Okay, I moved it such that the increment occurs at each successive hit.
By: frawd (frawd) 2010-05-19 04:41:39

Looks good, you could also add "dtmf.hits * DTMF_GSIZE" to the counter whenever there is a miss (and only on the first one), but I don't think incrementing a counter on each hit affects performance and your way is much more understandable when reading the code.

Last thing, I believe "event_len" should be initialized to '0' for the DTMF_BEGIN frame to have a '0' length (I'm not sure it matters).
By: Digium Subversion (svnbot) 2010-05-19 11:42:20

Repository: asterisk
Revision: 264204

U   trunk/main/dsp.c

------------------------------------------------------------------------
r264204 | tilghman | 2010-05-19 11:42:20 -0500 (Wed, 19 May 2010) | 9 lines

Keep track of digit duration, when we're decoding inband to pass DTMF frames.

(closes issue ASTERISK-16003)
Reported by: frawd
Patches:
      new_dtmf_dsp_len.patch uploaded by frawd (license 610)
      20100518__issue17235.diff.txt uploaded by tilghman (license 14)
Tested by: frawd

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=264204
By: Digium Subversion (svnbot) 2010-05-19 11:44:06

Repository: asterisk
Revision: 264205

_U  branches/1.6.2/
U   branches/1.6.2/main/dsp.c

------------------------------------------------------------------------
r264205 | tilghman | 2010-05-19 11:44:06 -0500 (Wed, 19 May 2010) | 16 lines

Merged revisions 264204 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
 r264204 | tilghman | 2010-05-19 11:42:20 -0500 (Wed, 19 May 2010) | 9 lines
 
 Keep track of digit duration, when we're decoding inband to pass DTMF frames.
 
 (closes issue ASTERISK-16003)
  Reported by: frawd
  Patches:
        new_dtmf_dsp_len.patch uploaded by frawd (license 610)
        20100518__issue17235.diff.txt uploaded by tilghman (license 14)
  Tested by: frawd
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=264205