[Home]

Summary:ASTERISK-14394: Repeated DTMF
Reporter:Frederic Jean (makafre)Labels:
Date Opened:2009-06-29 13:30:50Date Closed:2011-06-07 14:07:25
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/Interoperability
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:I am experiencing DTMF repetition (4 times) while using the following setup:

Zoiper -> (SIP/rfc2833) -> 1.4.25.1 -> get_data()

This is the only way I can reproduce the problem. IAX2 will work just fine.

Let me know if you need more info from my part.

Thanks.

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

#
[Jun 29 13:31:52] DEBUG[15662]: channel.c:2991 set_format: Set channel SIP/281827-b7dad8d0 to write format slin
#
[Jun 29 13:31:52] DEBUG[15662]: chan_sip.c:6911 transmit_response_with_sdp: Setting framing from config on incoming call
#
[Jun 29 13:31:52] DEBUG[15662]: chan_sip.c:6634 add_sdp: ** Our capability: 0x6 (gsm|ulaw) Video flag: True
#
[Jun 29 13:31:52] DEBUG[15662]: chan_sip.c:6635 add_sdp: ** Our prefcodec: 0x0 (nothing)
#
[Jun 29 13:31:52] DEBUG[15662]: chan_sip.c:6752 add_sdp: -- Done with adding codecs to SDP
#
[Jun 29 13:31:52] DEBUG[15662]: channel.c:2459 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
#
[Jun 29 13:31:52] DEBUG[15662]: chan_sip.c:6853 add_sdp: Done building SDP. Settling with this capability: 0x6 (gsm|ulaw)
#
   -- <SIP/281827-b7dad8d0> Playing 'mot-entrer-code-agent' (language 'en')
#
[Jun 29 13:31:52] DEBUG[15662]: rtp.c:2857 ast_rtp_write: Ooh, format changed from unknown to gsm
#
[Jun 29 13:31:52] DEBUG[15662]: rtp.c:2874 ast_rtp_write: Created smoother: format: 2 ms: 20 len: 33
#
[Jun 29 13:31:53] DEBUG[1332]: chan_iax2.c:8250 socket_process: Peer 5143947869: got pong, lastms 13, historicms 13, maxms 2000
#
[Jun 29 13:31:54] DEBUG[15662]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000001 (len = 4)
#
[Jun 29 13:31:54] DEBUG[15662]: rtp.c:626 send_dtmf: Sending dtmf: 49 (1), at 64.86.141.133
#
[Jun 29 13:31:54] DEBUG[15662]: channel.c:2991 set_format: Set channel SIP/281827-b7dad8d0 to write format gsm
#
[Jun 29 13:31:54] DEBUG[15662]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000001 (len = 4)
#
[Jun 29 13:31:54] DEBUG[15662]: rtp.c:626 send_dtmf: Sending dtmf: 49 (1), at 64.86.141.133
#
[Jun 29 13:31:54] DEBUG[15662]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000001 (len = 4)
#
[Jun 29 13:31:54] DEBUG[15662]: rtp.c:626 send_dtmf: Sending dtmf: 49 (1), at 64.86.141.133
#
[Jun 29 13:31:54] DEBUG[15662]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000001 (len = 4)
#
[Jun 29 13:31:54] DEBUG[15662]: rtp.c:626 send_dtmf: Sending dtmf: 49 (1), at 64.86.141.133
#
[Jun 29 13:31:55] DEBUG[15662]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000002 (len = 4)
#
[Jun 29 13:31:55] DEBUG[15662]: rtp.c:626 send_dtmf: Sending dtmf: 50 (2), at 64.86.141.133
#
[Jun 29 13:31:55] DEBUG[15662]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000002 (len = 4)
#
[Jun 29 13:31:55] DEBUG[15662]: rtp.c:626 send_dtmf: Sending dtmf: 50 (2), at 64.86.141.133
#
[Jun 29 13:31:55] DEBUG[15662]: channel.c:2991 set_format: Set channel SIP/281827-b7dad8d0 to write format slin
#
[Jun 29 13:31:55] DEBUG[15662]: rtp.c:2684 ast_rtp_raw_write: Difference is 10016, ms is 1272
Comments:By: Frederic Jean (makafre) 2009-06-29 14:05:50

This specific issue is while using the get_data AGI command:

$user = $AGI->get_data('mot-entrer-code-agent', 6000, 6);

get_data() returns right after I pressed the 2 digits because
at that moment 7 or 8 DTMF were already "seen".
By: Russell Bryant (russell) 2009-06-29 16:54:32

This issue was resolved in 1.4 rev 192633 from issue ASTERISK-14070.
By: Frederic Jean (makafre) 2009-06-30 14:03:03

Ok, I just reopened it as 15036 is already in 1.4.25.1 and the problem persists. I'll add some notes on how to reproduce.
By: Russell Bryant (russell) 2009-06-30 14:25:09

Ah, sorry about that.  I may have had this issue confused with a different one.
By: Frederic Jean (makafre) 2009-06-30 14:35:17

Here is more info :-) to reproduce the problem; I am using rfc2833 over SIP and dialling
an extension that calls an AGI script which performs the get_data() function.
The problem is with that function that returns repeated digits.


SOFTWARE:

SoftPhone: Free Zoiper
Asterisk release: 1.4.25.1

DIALPLAN:

[test]
exten => _*7999,1,Agi(test.agi)

TEST.AGI:

#!/usr/bin/perl
use Asterisk::AGI;
$AGI = new Asterisk::AGI;
my %input = $AGI->ReadParse();
exit unless $input{'request'};
$SIG{HUP}  = 'ignore_hup';

my $user = $AGI->get_data('dir-welcome', 6000, 6);

1;

SIP_BUDDIES:

mysql> select * from sip_buddies where name=281827\G;
*************************** 1. row ***************************
           id: 77
         name: 281827
          nat: no
         type: friend
  accountcode: <removed>
     amaflags: billing
   call-limit: 10
     callerid: NULL
cancallforward: no
  canreinvite: no
      context: test
    defaultip: NULL
     dtmfmode: rfc2833
     fromuser: NULL
   fromdomain: NULL
     language: en
         mask: NULL
      qualify: no
       secret: <removed>
     disallow: all
        allow: g729;ilbc;gsm;ulaw;alaw
         port: 63548
    regserver:
   regseconds: 1246392521
     username: 281827
  defaultuser:
       ipaddr: <removed>
  fullcontact: sip:281827@<removed>:63548;rinstance=a4eb714e2266a140
         host: dynamic
       apptag: 0
       lastms: 0
1 row in set (0.00 sec)

ACTION:

1- Dial *7999 from Zoiper.
2- Hear the welcome prompt message
3- Press 1 digit on zoiper dialpad (e.g. '3')

RESULT:

[Jun 30 15:19:37] DEBUG[19592]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000003 (len = 4)
[Jun 30 15:19:37] DEBUG[19592]: rtp.c:626 send_dtmf: Sending dtmf: 51 (3), at 64.86.141.133
[Jun 30 15:19:37] DEBUG[19592]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000003 (len = 4)
[Jun 30 15:19:37] DEBUG[19592]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000003 (len = 4)
[Jun 30 15:19:37] DEBUG[19592]: rtp.c:727 process_rfc2833: - RTP 2833 Event: 00000003 (len = 4)
[Jun 30 15:19:37] DEBUG[19592]: rtp.c:626 send_dtmf: Sending dtmf: 51 (3), at 64.86.141.133

->  So it seems that when pressing 1 digits, 4 are taken into account.
By: Dmitry Andrianov (dimas) 2009-07-06 09:49:15

1. Do you have rfc2833compensate set anywhere at sip.conf? I would recommend turning it off unless you need to communicate with pre 1.4 systems.

2. Please provide RTP/DTMF debug output for the scenario you are describing.
Edit logger.conf to enable DTMF logging to the console, restart and also turn RTP debugging on (see rtp debug CLI command).

3. What version of Zoiper are you using?


By: Frederic Jean (makafre) 2009-08-07 14:56:47

Ok, sorry for the time it took to respond as I was on vacation. Please note that the problem seems to come from ZoIPER itself as today I reinstalled it and doing this test again, everything was OK. You can then close this ticket; if there is anything else I will provide the log as suggested by dimas. It might have been a codec change or something similar as well, in anyway I will keep you posted. Thanks a lot for your support!
By: Jason Parker (jparker) 2009-08-07 16:42:00

Closing per reporter.