[Home]

Summary:ASTERISK-09831: if asterisk is received get perpetual dtmf
Reporter:John Covici (covici)Labels:
Date Opened:2007-07-07 09:55:08Date Closed:2011-06-07 14:02:53
Priority:MajorRegression?No
Status:Closed/CompleteComponents:Channels/chan_zap
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) rtp-debug.log
Description:if I call my cell phone using asterisk, and if te cell phone sends * a perpetual dtmf exists till the call is hung up.

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

I am using a provider with SIP inband dtmf.  If I call using pstn this does not happen.  I am using a Digium 400p -- fxs port for the handset and fxo to pstn.
Comments:By: John Covici (covici) 2007-07-07 10:03:31

Here is the log output.
[Jul  3 03:23:07] VERBOSE[26933] logger.c:     -- Executing [s@macro-dialout-trunk:14] Dial("Zap/1-1", "SIP/galaxyvoice/7034314045||TW") in new stack
[Jul  3 03:23:07] VERBOSE[26933] logger.c:     -- Called galaxyvoice/7034314045
[Jul  3 03:23:07] VERBOSE[26933] logger.c:     -- SIP/galaxyvoice-0820cdc0 is making progress passing it to Zap/1-1
[Jul  3 03:23:07] DEBUG[26933] chan_zap.c: Received AST_CONTROL_PROGRESS on Zap/1-1
[Jul  3 03:23:23] NOTICE[26851] chan_iax2.c: Peer 'covici' is not dynamic (from 140.239.173.226)
[Jul  3 03:23:25] VERBOSE[26933] logger.c:     -- SIP/galaxyvoice-0820cdc0 answered Zap/1-1
[Jul  3 03:23:25] DEBUG[26933] chan_zap.c: Took Zap/1-1 off hook
[Jul  3 03:23:35] DTMF[26933] channel.c: DTMF end '*' received on SIP/galaxyvoice-0820cdc0, duration 0 ms
[Jul  3 03:23:35] DTMF[26933] channel.c: DTMF begin emulation of '*' with duration 100 queued on SIP/galaxyvoice-0820cdc0
[Jul  3 03:23:35] DEBUG[26933] chan_zap.c: Started VLDTMF digit '*'
[Jul  3 03:23:46] VERBOSE[26933] logger.c:   == Spawn extension (macro-dialout-trunk, s, 14) exited non-zero on 'Zap/1-1' in macro 'dialout-trunk'
[Jul  3 03:23:46] VERBOSE[26933] logger.c:   == Spawn extension (macro-dialout-trunk, s, 14) exited non-zero on 'Zap/1-1'
[Jul  3 03:23:46] VERBOSE[26933] logger.c:     -- Executing [h@macro-dialout-trunk:1] Macro("Zap/1-1", "hangupcall") in new stack
[Jul  3 03:23:46] VERBOSE[26933] logger.c:     -- Executing [s@macro-hangupcall:1] ResetCDR("Zap/1-1", "w") in new stack
[Jul  3 03:23:46] DEBUG[26933] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
[Jul  3 03:23:46] DEBUG[26933] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES ('2007-07-03 03:23:01','\"John Covici\" <7037775986>','7037775986','7034314045','from-internal', 'Zap/1-1','SIP/galaxyvoice-0820cdc0','ResetCDR','w',45,21,'ANSWERED',3,'')
[Jul  3 03:23:46] DEBUG[26933] app_macro.c: Executed application: ResetCDR
[Jul  3 03:23:46] VERBOSE[26933] logger.c:     -- Executing [s@macro-hangupcall:2] NoCDR("Zap/1-1", "") in new stack
[Jul  3 03:23:46] DEBUG[26933] app_macro.c: Executed application: NoCDR
[Jul  3 03:23:46] VERBOSE[26933] logger.c:     -- Executing [s@macro-hangupcall:3] GotoIf("Zap/1-1", "1?skiprg") in new stack
[Jul  3 03:23:46] VERBOSE[26933] logger.c:     -- Goto (macro-hangupcall,s,6)
[Jul  3 03:23:46] DEBUG[26933] app_macro.c: Executed application: GotoIf
[Jul  3 03:23:46] VERBOSE[26933] logger.c:     -- Executing [s@macro-hangupcall:6] GotoIf("Zap/1-1", "1?theend") in new stack
[Jul  3 03:23:46] VERBOSE[26933] logger.c:     -- Goto (macro-hangupcall,s,9)
[Jul  3 03:23:46] DEBUG[26933] app_macro.c: Executed application: GotoIf
[Jul  3 03:23:46] VERBOSE[26933] logger.c:     -- Executing [s@macro-hangupcall:9] Wait("Zap/1-1", "5") in new stack
[Jul  3 03:23:51] DEBUG[26933] app_macro.c: Executed application: Wait
[Jul  3 03:23:51] VERBOSE[26933] logger.c:     -- Executing [s@macro-hangupcall:10] Hangup("Zap/1-1", "") in new stack
[Jul  3 03:23:51] VERBOSE[26933] logger.c:   == Spawn extension (macro-hangupcall, s, 10) exited non-zero on 'Zap/1-1' in macro 'hangupcall'
[Jul  3 03:23:51] VERBOSE[26933] logger.c:   == Spawn extension (macro-hangupcall, s, 10) exited non-zero on 'Zap/1-1'
[Jul  3 03:23:51] VERBOSE[26933] logger.c:     -- Hungup 'Zap/1-1'
[Jul  3 03:23:55] DEBUG[26847] chan_zap.c: Message status for 200 changed from -1 to 0 on 1
[Jul  3 03:24:13] NOTICE[26856] chan_iax2.c: Peer 'covici' is not dynamic (from 140.239.173.226)


Now what I tried just for grins, was to route the call out my fxo
rather than my sip provider and I did not have the dtmf problem when
doing that.  Here is the log output for that one.

[Jul  3 03:32:10] VERBOSE[27683] logger.c:     -- Executing [s@macro-dialout-trunk:14] Dial("Zap/1-1", "ZAP/4/www7034314045||TW") in new stack
[Jul  3 03:32:10] DEBUG[27683] chan_zap.c: Dialing 'www7034314045'
[Jul  3 03:32:10] DEBUG[27683] chan_zap.c: Deferring dialing...
[Jul  3 03:32:10] VERBOSE[27683] logger.c:     -- Called 4/www7034314045
[Jul  3 03:32:14] DEBUG[27683] chan_zap.c: Engaged echo training on channel 4
[Jul  3 03:32:15] DEBUG[27683] chan_zap.c: Echo cancellation already on
[Jul  3 03:32:15] VERBOSE[27683] logger.c:     -- Zap/4-1 answered Zap/1-1
[Jul  3 03:32:15] DEBUG[27683] chan_zap.c: Took Zap/1-1 off hook
[Jul  3 03:32:34] NOTICE[26852] chan_iax2.c: Peer 'covici' is not dynamic (from 140.239.173.226)
[Jul  3 03:32:37] DTMF[27683] channel.c: DTMF end '*' received on Zap/4-1, duration 0 ms
[Jul  3 03:32:37] DTMF[27683] channel.c: DTMF begin emulation of '*' with duration 100 queued on Zap/4-1
[Jul  3 03:32:37] DEBUG[27683] chan_zap.c: Started VLDTMF digit '*'
[Jul  3 03:32:37] DTMF[27683] channel.c: DTMF end emulation of '*' queued on Zap/4-1
[Jul  3 03:32:37] DEBUG[27683] chan_zap.c: Ending VLDTMF digit '*'
[Jul  3 03:32:40] DTMF[27683] channel.c: DTMF end '*' received on Zap/4-1, duration 0 ms
[Jul  3 03:32:40] DTMF[27683] channel.c: DTMF begin emulation of '*' with duration 100 queued on Zap/4-1
[Jul  3 03:32:40] DEBUG[27683] chan_zap.c: Started VLDTMF digit '*'
[Jul  3 03:32:40] DTMF[27683] channel.c: DTMF end emulation of '*' queued on Zap/4-1
[Jul  3 03:32:40] DEBUG[27683] chan_zap.c: Ending VLDTMF digit '*'
[Jul  3 03:32:55] VERBOSE[27683] logger.c:     -- Hungup 'Zap/4-1'
By: Joshua C. Colp (jcolp) 2007-07-08 20:18:08

Are you using internal timing? (it would be enabled in asterisk.conf) Can you attach an rtp debug so I can see the stream from your provider?
By: John Covici (covici) 2007-07-10 05:58:52

Timing is not mentioned in asterisk.conf and I am using a zaptel card, so I imagine the timing would come from there.  I am attaching the debug output for rtp from the time the call is answered till the hangup.
By: Joshua C. Colp (jcolp) 2007-07-10 08:16:13

Please turn on internal_timing in asterisk.conf and try again.
By: John Covici (covici) 2007-07-11 02:40:16

I turned on internal timing by putting an [options] section in asterisk.conf and the line
internal_timing = yes
but it did not make a difference.
By: Mike Loebl (mloebl) 2007-09-12 20:20:57

I'm seeing a very similiar problem here with a 400P card and GalaxyVoice as well.  If I dial in or receive a call from one of the analog lines on the 400P, it will randomly get stuck transmitting a tone until I hang up.  If I use a SIP phone, the problem does not occur.
By: John Covici (covici) 2007-09-12 22:52:52

With me, using an analog line to the cell phone directly works, using Galaxyvoice does not!

I may sign up with another provider to see if that makes a difference.  I will let you know if it does.
By: John Covici (covici) 2007-09-16 16:03:21

I have discovered something interesting concerning this bug -- I have been using another SIP provider  and I am not seeing the problem with the new provider.  Very strange!
By: deeperror (deeperror) 2007-10-03 14:26:49

Also experiencing same issue with 1.4.11 and rhino r4t1 card.  

[Oct  3 14:02:12] DEBUG[16892] chan_zap.c: Started VLDTMF digit '8'
By: Joshua C. Colp (jcolp) 2007-12-18 10:09:48.000-0600

covici: Quite strange indeed... I saw nothing to indicate why it's happening...

deeperror: There have been a few DTMF improvements since that version, and without full information it is hard to determine things.
By: Jason Parker (jparker) 2007-12-26 15:44:04.000-0600

Closing.

This appears to have been a problem with a specific voip provider.

deeperror, if you can reproduce your issue, please contact a bug marshal to get this bug reopened, or open a new issue.