[Freeswitch-users] Unable to detect the digits in demo IVR when connecting via DID inbound

Thu Jun 3 22:02:32 PDT 2010

Hello all,

Sorry to bother all, I had been trying so hard to create a DID-inbound that
will route to demo IVR(5000 XML default) and allow user to press and select
the menu via pressing  digits. It works perfect when I dial 5000 from any of
my local extension.
However, when I try to call the DID, and got connected to the voice mail
successfully, but the digit is unable to be detected.
Wondering if my configuration got something wrong?

what i had created in the public\01_mydivert.xml (i put the config inside
the public context and setting mydivert to connect to my pbxserver at port
5080) file is as follow:

  <extension name="didfromMyDivert">

        <condition field="network_addr" expression="^78\.46\.23\.202$" >

                <action application="info" />

                <action application="set" data="domain_name=$${domain}" />

                <action application="set"
> data="transfer_ringback=$${uk_ring}" />

                <action application="transfer" data="5000 XML default" />

        </condition>

  </extension>

and when i call the DID number hosted by mydivert.com, the log file shows
when i press 1, it just do nothing and keep playing to "please press 2 or
something"

2010-06-04 12:23:59.414516 [DEBUG] switch_ivr_play_say.c:244 Handle
> play-file:[voicemail/vm-press.wav] (en:en)

2010-06-04 12:23:59.414516 [DEBUG] switch_ivr_play_say.c:1152 Codec
> Activated L16 at 8000hz 1 channels 20ms

2010-06-04 12:23:59.814618 [DEBUG] switch_ivr_play_say.c:1444 done playing
> file

2010-06-04 12:23:59.933629 [DEBUG] switch_ivr_play_say.c:244 Handle
> play-file:[digits/1.wav] (en:en)

2010-06-04 12:23:59.933629 [DEBUG] switch_ivr_play_say.c:1152 Codec
> Activated L16 at 8000hz 1 channels 20ms

2010-06-04 12:24:00.394005 [DEBUG] switch_ivr_play_say.c:1444 done playing
> file

2010-06-04 12:24:00.514102 [DEBUG] switch_ivr_play_say.c:244 Handle
> play-file:[ivr/ivr-to_do_a_freeswitch_echo_test.wav] (en:en)

2010-06-04 12:24:00.514102 [DEBUG] switch_ivr_play_say.c:1152 Codec
> Activated L16 at 8000hz 1 channels 20ms

> 2010-06-04 12:24:01.596587 [DEBUG] switch_rtp.c:2841 RTP RECV DTMF 1:1280

2010-06-04 12:24:01.599459 [DEBUG] zap_io.c:2061 4:1 GENERATE DTMF [1]

2010-06-04 12:24:01.639329 [DEBUG] mod_openzap.c:721 queue DTMF [1]

> 2010-06-04 12:24:01.654270 [DEBUG] switch_rtp.c:1928 Send start packet for
> [1] ts=172800 dur=160/160/2000 seq=63824

2010-06-04 12:24:01.674124 [DEBUG] switch_rtp.c:1864 Send middle packet for
> [1] ts=172800 dur=320/320/2000 seq=63825

2010-06-04 12:24:01.694115 [DEBUG] switch_rtp.c:1864 Send middle packet for
> [1] ts=172800 dur=480/480/2000 seq=63826

2010-06-04 12:24:01.714098 [DEBUG] switch_rtp.c:1864 Send middle packet for
> [1] ts=172800 dur=640/640/2000 seq=63827

2010-06-04 12:24:01.733685 [DEBUG] switch_rtp.c:1864 Send middle packet for
> [1] ts=172800 dur=800/800/2000 seq=63828

2010-06-04 12:24:01.754129 [DEBUG] switch_rtp.c:1864 Send middle packet for
> [1] ts=172800 dur=960/960/2000 seq=63829

2010-06-04 12:24:01.774264 [DEBUG] switch_rtp.c:1864 Send middle packet for
> [1] ts=172800 dur=1120/1120/2000 seq=63830

2010-06-04 12:24:01.795396 [DEBUG] switch_rtp.c:1864 Send middle packet for
> [1] ts=172800 dur=1280/1280/2000 seq=63831

2010-06-04 12:24:01.814112 [DEBUG] switch_rtp.c:1864 Send middle packet for
> [1] ts=172800 dur=1440/1440/2000 seq=63832

2010-06-04 12:24:01.834315 [DEBUG] switch_rtp.c:1864 Send middle packet for
> [1] ts=172800 dur=1600/1600/2000 seq=63833

2010-06-04 12:24:01.853792 [DEBUG] switch_rtp.c:1864 Send middle packet for
> [1] ts=172800 dur=1760/1760/2000 seq=63834

2010-06-04 12:24:01.874010 [DEBUG] switch_rtp.c:1864 Send middle packet for
> [1] ts=172800 dur=1920/1920/2000 seq=63835

2010-06-04 12:24:01.894444 [DEBUG] switch_rtp.c:1864 Send end packet for [1]
> ts=172800 dur=2080/2080/2000 seq=63836

2010-06-04 12:24:01.894444 [DEBUG] switch_rtp.c:1864 Send end packet for [1]
> ts=172800 dur=2080/2080/2000 seq=63837

2010-06-04 12:24:01.894444 [DEBUG] switch_rtp.c:1864 Send end packet for [1]
> ts=172800 dur=2080/2080/2000 seq=63838

2010-06-04 12:24:02.333695 [DEBUG] switch_ivr_play_say.c:1444 done playing
> file

2010-06-04 12:24:02.434126 [DEBUG] switch_ivr_play_say.c:244 Handle
> play-file:[ivr/ivr-please.wav] (en:en)

2010-06-04 12:24:02.434126 [DEBUG] switch_ivr_play_say.c:1152 Codec
> Activated L16 at 8000hz 1 channels 20ms

2010-06-04 12:24:02.854127 [DEBUG] switch_ivr_play_say.c:1444 done playing
> file

2010-06-04 12:24:02.974217 [DEBUG] switch_ivr_play_say.c:244 Handle
> play-file:[voicemail/vm-press.wav] (en:en)

2010-06-04 12:24:02.974217 [DEBUG] switch_ivr_play_say.c:1152 Codec
> Activated L16 at 8000hz 1 channels 20ms

2010-06-04 12:24:03.374396 [DEBUG] switch_ivr_play_say.c:1444 done playing
> file

2010-06-04 12:24:03.494367 [DEBUG] switch_ivr_play_say.c:244 Handle
> play-file:[digits/2.wav] (en:en)

2010-06-04 12:24:03.494367 [DEBUG] switch_ivr_play_say.c:1152 Codec
> Activated L16 at 8000hz 1 channels 20ms

and the app info for this DID inbound is as follow:

2010-06-04 12:23:41.001560 [INFO] mod_dptools.c:973 CHANNEL_DATA:

Channel-State: [CS_EXECUTE]

Channel-State-Number: [4]

Channel-Name: [sofia/external/24172200 at 78.46.23.202]

Unique-ID: [f456ff9c-6f90-11df-84c8-3b7d920feee8]

Call-Direction: [inbound]

Presence-Call-Direction: [inbound]

Answer-State: [ringing]

Channel-Read-Codec-Name: [PCMU]

Channel-Read-Codec-Rate: [8000]

Channel-Write-Codec-Name: [PCMU]

Channel-Write-Codec-Rate: [8000]

Caller-Username: [24172200]

Caller-Dialplan: [XML]

Caller-Caller-ID-Name: [24172200]

Caller-Caller-ID-Number: [24172200]

Caller-Network-Addr: [78.46.23.202]

Caller-ANI: [24172200]

Caller-Destination-Number: [85236931541]

Caller-Unique-ID: [f456ff9c-6f90-11df-84c8-3b7d920feee8]

Caller-Source: [mod_sofia]

Caller-Context: [public]

Caller-Channel-Name: [sofia/external/24172200 at 78.46.23.202]

Caller-Profile-Index: [1]

Caller-Profile-Created-Time: [1275625420968944]

Caller-Channel-Created-Time: [1275625420968944]

Caller-Channel-Answered-Time: [0]

Caller-Channel-Progress-Time: [0]

Caller-Channel-Progress-Media-Time: [0]

Caller-Channel-Hangup-Time: [0]

Caller-Channel-Transfer-Time: [0]

Caller-Screen-Bit: [false]

Caller-Privacy-Hide-Name: [false]

Caller-Privacy-Hide-Number: [false]

variable_direction: [inbound]

variable_uuid: [f456ff9c-6f90-11df-84c8-3b7d920feee8]

variable_sip_local_network_addr: [192.168.8.232]

variable_sip_network_ip: [78.46.23.202]

variable_sip_network_port: [5060]

variable_sip_received_ip: [78.46.23.202]

variable_sip_received_port: [5060]

variable_sip_via_protocol: [udp]

variable_sip_from_user: [24172200]

variable_sip_from_uri: [24172200 at 78.46.23.202]

variable_sip_from_host: [78.46.23.202]

variable_sip_from_user_stripped: [24172200]

variable_sip_from_tag: [as750696c8]

variable_sofia_profile_name: [external]

variable_sip_Remote-Party-ID: ["24172200"
<sip:24172200 at 78.46.23.202<sip%3A24172200 at 78.46.23.202>
> >;privacy=off;screen=no]

variable_sip_cid_type: [rpid]

variable_sip_full_via: [SIP/2.0/UDP 78.46.23.202:5060
> ;branch=z9hG4bK32bcbf22]

variable_sip_from_display: [24172200]

variable_sip_full_from: ["24172200"
<sip:24172200 at 78.46.23.202<sip%3A24172200 at 78.46.23.202>
> >;tag=as750696c8]

variable_sip_full_to: [<sip:85236931541 at jessnruss.dyndns.org:5080>]

variable_sip_req_user: [85236931541]

variable_sip_req_port: [5080]

variable_sip_req_uri: [85236931541 at jessnruss.dyndns.org:5080]

variable_sip_req_host: [jessnruss.dyndns.org]

variable_sip_to_user: [85236931541]

variable_sip_to_port: [5080]

variable_sip_to_uri: [85236931541 at jessnruss.dyndns.org:5080]

variable_sip_to_host: [jessnruss.dyndns.org]

variable_sip_contact_user: [24172200]

variable_sip_contact_uri: [24172200 at 78.46.23.202]

variable_sip_contact_host: [78.46.23.202]

variable_channel_name: [sofia/external/24172200 at 78.46.23.202]

variable_sip_call_id: [6b53813d4bb32def4d2931960d17e7ee at 78.46.23.202]

variable_sip_user_agent: [Asterisk]

variable_sip_via_host: [78.46.23.202]

variable_sip_via_port: [5060]

variable_max_forwards: [70]

variable_switch_r_sdp: [v=0

o=root 1913419625 1913419625 IN IP4 78.46.23.202

s=Asterisk PBX 1.6.0.26

c=IN IP4 78.46.23.202

t=0 0

m=audio 19066 RTP/AVP 18 0 8 101

a=rtpmap:18 G729/8000

a=fmtp:18 annexb=no

a=rtpmap:0 PCMU/8000

a=rtpmap:8 PCMA/8000

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-16

a=silenceSupp:off - - - -

a=ptime:20

]

variable_remote_media_ip: [78.46.23.202]

variable_remote_media_port: [19066]

variable_sip_use_codec_name: [PCMU]

variable_sip_use_codec_rate: [8000]

variable_sip_use_codec_ptime: [20]

variable_read_codec: [PCMU]

variable_read_rate: [8000]

variable_write_codec: [PCMU]

variable_write_rate: [8000]

variable_endpoint_disposition: [RECEIVED]

variable_outside_call: [true]

variable_current_application: [info]

However, if i call the demo IVR 5000 internally, the log shows really good.

2010-06-04 12:30:22.394100 [DEBUG] switch_ivr_play_say.c:244 Handle
> play-file:[voicemail/vm-press.wav] (en:en)

2010-06-04 12:30:22.394100 [DEBUG] switch_ivr_play_say.c:1152 Codec
> Activated L16 at 8000hz 1 channels 20ms

2010-06-04 12:30:22.794457 [DEBUG] switch_ivr_play_say.c:1444 done playing
> file

2010-06-04 12:30:22.914491 [DEBUG] switch_ivr_play_say.c:244 Handle
> play-file:[digits/1.wav] (en:en)

2010-06-04 12:30:22.914491 [DEBUG] switch_ivr_play_say.c:1152 Codec
> Activated L16 at 8000hz 1 channels 20ms

2010-06-04 12:30:23.373688 [DEBUG] switch_ivr_play_say.c:1444 done playing
> file

2010-06-04 12:30:23.474363 [DEBUG] switch_ivr_play_say.c:244 Handle
> play-file:[ivr/ivr-to_do_a_freeswitch_echo_test.wav] (en:en)

2010-06-04 12:30:23.474363 [DEBUG] switch_ivr_play_say.c:1152 Codec
> Activated L16 at 8000hz 1 channels 20ms

> 2010-06-04 12:30:25.215382 [DEBUG] switch_rtp.c:2841 RTP RECV DTMF 1:960

2010-06-04 12:30:25.215382 [DEBUG] switch_ivr_play_say.c:1444 done playing
> file

2010-06-04 12:30:25.334284 [DEBUG] switch_ivr_menu.c:329 waiting for 3/4
> digits t/o 2000

2010-06-04 12:30:27.354514 [DEBUG] switch_ivr_menu.c:376 digits '1'

2010-06-04 12:30:27.354514 [DEBUG] switch_ivr_menu.c:470 action regex [1]
> [/^(10[01][0-9])$/] [0]

> 2010-06-04 12:30:27.354514 [DEBUG] switch_ivr_menu.c:488 IVR action on menu
> 'demo_ivr' matched '1' param 'bridge sofia/
> 192.168.8.232/888 at conference.freeswitch.org'

> 2010-06-04 12:30:27.354514 [DEBUG] switch_ivr_menu.c:492
> switch_ivr_menu_execute todo=[2]

EXECUTE sofia/internal/1001 at jessnruss.dyndns.org bridge(sofia/
> 192.168.8.232/888 at conference.freeswitch.org)

from the two logs above, what i can see the difference is the line:

in [FAILURE log]
2010-06-04 12:24:01.596587 [DEBUG] switch_rtp.c:2841 RTP RECV DTMF 1:1280

in [SUCCESS log]
2010-06-04 12:30:25.215382 [DEBUG] switch_rtp.c:2841 RTP RECV DTMF 1:960

i am wondering if is there anything to do with this line?

any help is really appreciated.

Cheers,
Russell Kwok
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20100604/e2760113/attachment-0001.html 