Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

No DTMF in conference #93

Open
Syfer opened this issue Jul 2, 2012 · 14 comments
Open

No DTMF in conference #93

Syfer opened this issue Jul 2, 2012 · 14 comments

Comments

@Syfer
Copy link

Syfer commented Jul 2, 2012

After i connect into conference, any dtmf action is making an error "dmachine overflow error!".

Conference config:
$params = array(
"maxMembers" => 3,
"callbackUrl" => $this->confCallbackUrl,
"callbackMethod" => "POST",
"digitsMatch" => '1',
"endConferenceOnExit" => "true",
);
$conference = new Conference($conferenceName, $params);

Any idea? Please help.

FS Log:
2012-07-02 18:48:37.879793 [DEBUG] switch_ivr_originate.c:1958 Parsing global variables
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [plivo_request_uuid]=[638c1fdc-c45d-11e1-be60-5404a6c00bfd]
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [plivo_answer_url]=[http://mydomain.com/plivo/callback?event=answered]
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [plivo_ring_url]=[http://mydomain.com/plivo/callback?event=ringing]
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [plivo_hangup_url]=[http://mydomain.com/plivo/callback?event=hangup]
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [origination_caller_id_number]=[PlivoCaller]
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [bridge_early_media]=[true]
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [hangup_after_bridge]=[true]
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [plivo_from]=[PlivoCaller]
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [plivo_to]=[1007]
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [plivo_app]=[true]
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [absolute_codec_string]=[PCMA]
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [originate_timeout]=[60]
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [ignore_early_media]=[true]
2012-07-02 18:48:37.879793 [DEBUG] switch_ivr_originate.c:1958 Parsing global variables
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [sip_invite_domain]=[192.168.10.151]
2012-07-02 18:48:37.879793 [DEBUG] switch_event.c:1473 Parsing variable [presence_id]=[1007@192.168.10.151]
2012-07-02 18:48:37.879793 [NOTICE] switch_channel.c:926 New Channel sofia/internal/sip:1007@192.168.10.7:6090 [638c7b6c-c45d-11e1-a0f5-f1aa4eeaf012]
2012-07-02 18:48:37.879793 [DEBUG] mod_sofia.c:4775 (sofia/internal/sip:1007@192.168.10.7:6090) State Change CS_NEW -> CS_INIT
2012-07-02 18:48:37.879793 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:1007@192.168.10.7:6090) Running State Change CS_INIT
2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/sip:1007@192.168.10.7:6090) State INIT
2012-07-02 18:48:37.879793 [DEBUG] mod_sofia.c:85 sofia/internal/sip:1007@192.168.10.7:6090 SOFIA INIT
2012-07-02 18:48:37.879793 [DEBUG] sofia_glue.c:2602 Local SDP:
v=0
o=FreeSWITCH 1341221011 1341221012 IN IP4 192.168.10.151
s=FreeSWITCH
c=IN IP4 192.168.10.151
t=0 0
m=audio 23106 RTP/AVP 8 101 13
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2012-07-02 18:48:37.879793 [DEBUG] mod_sofia.c:125 (sofia/internal/sip:1007@192.168.10.7:6090) State Change CS_INIT -> CS_ROUTING
2012-07-02 18:48:37.879793 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/sip:1007@192.168.10.7:6090) State INIT going to sleep
2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:1007@192.168.10.7:6090) Running State Change CS_ROUTING
2012-07-02 18:48:37.879793 [DEBUG] switch_channel.c:1919 (sofia/internal/sip:1007@192.168.10.7:6090) Callstate Change DOWN -> RINGING
2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/sip:1007@192.168.10.7:6090) State ROUTING
2012-07-02 18:48:37.879793 [DEBUG] mod_sofia.c:148 sofia/internal/sip:1007@192.168.10.7:6090 SOFIA ROUTING
2012-07-02 18:48:37.879793 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sip:1007@192.168.10.7:6090) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2012-07-02 18:48:37.879793 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/sip:1007@192.168.10.7:6090) State ROUTING going to sleep
2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:1007@192.168.10.7:6090) Running State Change CS_CONSUME_MEDIA
2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:452 (sofia/internal/sip:1007@192.168.10.7:6090) State CONSUME_MEDIA
2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:452 (sofia/internal/sip:1007@192.168.10.7:6090) State CONSUME_MEDIA going to sleep
2012-07-02 18:48:37.879793 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:37.879793 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:1007@192.168.10.7:6090 entering state [calling][0]
2012-07-02 18:48:37.979792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:37.979792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:37.979792 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:1007@192.168.10.7:6090 entering state [proceeding][180]
2012-07-02 18:48:37.979792 [NOTICE] sofia.c:5930 Ring-Ready sofia/internal/sip:1007@192.168.10.7:6090!
2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.499792 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:1007@192.168.10.7:6090 entering state [completing][200]
2012-07-02 18:48:40.499792 [DEBUG] sofia.c:5849 Remote SDP:
v=0
o=- 28658973 28659050 IN IP4 192.168.10.7
s=eyeBeam
c=IN IP4 192.168.10.7
t=0 0
m=audio 6096 RTP/AVP 8 101
a=rtpmap:8 pcma/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=alt:1 1 : CA6E622C DD6697DD 192.168.10.7 6096

2012-07-02 18:48:40.499792 [DEBUG] sofia_glue.c:3941 Looking for zrtp-hash
2012-07-02 18:48:40.499792 [DEBUG] sofia_glue.c:3919 Deciding whether to pass zrtp-hash between legs
2012-07-02 18:48:40.499792 [DEBUG] sofia_glue.c:3921 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.499792 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:1007@192.168.10.7:6090 entering state [ready][200]
2012-07-02 18:48:40.499792 [DEBUG] sofia_glue.c:3941 Looking for zrtp-hash
2012-07-02 18:48:40.499792 [DEBUG] sofia_glue.c:3919 Deciding whether to pass zrtp-hash between legs
2012-07-02 18:48:40.499792 [DEBUG] sofia_glue.c:3921 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
2012-07-02 18:48:40.499792 [DEBUG] sofia_glue.c:5034 Audio Codec Compare [pcma:8:8000:20:64000]/[PCMA:8:8000:20:64000]
2012-07-02 18:48:40.499792 [DEBUG] sofia_glue.c:3020 Set Codec sofia/internal/sip:1007@192.168.10.7:6090 PCMA/8000 20 ms 160 samples 64000 bits
2012-07-02 18:48:40.499792 [DEBUG] switch_core_codec.c:111 sofia/internal/sip:1007@192.168.10.7:6090 Original read codec set to PCMA:8
2012-07-02 18:48:40.499792 [DEBUG] sofia_glue.c:5148 Set 2833 dtmf send payload to 101
2012-07-02 18:48:40.499792 [DEBUG] sofia_glue.c:3269 AUDIO RTP [sofia/internal/sip:1007@192.168.10.7:6090] 192.168.10.151 port 23106 -> 192.168.10.7 port 6096 codec: 8 ms: 20
2012-07-02 18:48:40.499792 [DEBUG] switch_rtp.c:1861 Starting timer [soft] 160 bytes per 20ms
2012-07-02 18:48:40.499792 [DEBUG] sofia_glue.c:3533 Set 2833 dtmf send payload to 101
2012-07-02 18:48:40.499792 [DEBUG] sofia_glue.c:3539 Set 2833 dtmf receive payload to 101
2012-07-02 18:48:40.499792 [DEBUG] sofia_glue.c:3566 sofia/internal/sip:1007@192.168.10.7:6090 Set rtp dtmf delay to 40
2012-07-02 18:48:40.499792 [DEBUG] switch_channel.c:3301 (sofia/internal/sip:1007@192.168.10.7:6090) Callstate Change RINGING -> ACTIVE
2012-07-02 18:48:40.499792 [NOTICE] sofia.c:6573 Channel [sofia/internal/sip:1007@192.168.10.7:6090] has been answered
2012-07-02 18:48:40.499792 [DEBUG] switch_ivr_originate.c:3341 Originate Resulted in Success: [sofia/internal/sip:1007@192.168.10.7:6090]
2012-07-02 18:48:40.499792 [DEBUG] switch_ivr_originate.c:3341 Originate Resulted in Success: [sofia/internal/sip:1007@192.168.10.7:6090]
2012-07-02 18:48:40.499792 [INFO] switch_channel.c:2761 sofia/internal/sip:1007@192.168.10.7:6090 Flipping CID from "" to "Outbound Call" <1007>
2012-07-02 18:48:40.499792 [DEBUG] mod_commands.c:3616 (sofia/internal/sip:1007@192.168.10.7:6090) State Change CS_CONSUME_MEDIA -> CS_EXECUTE
2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:1229 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.499792 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:1007@192.168.10.7:6090) Running State Change CS_EXECUTE
2012-07-02 18:48:40.499792 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/sip:1007@192.168.10.7:6090) State EXECUTE
2012-07-02 18:48:40.499792 [DEBUG] mod_sofia.c:241 sofia/internal/sip:1007@192.168.10.7:6090 SOFIA EXECUTE
2012-07-02 18:48:40.499792 [DEBUG] switch_core_state_machine.c:196 sofia/internal/sip:1007@192.168.10.7:6090 Standard EXECUTE
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 socket(127.0.0.1:8084 async full)
2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.519795 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:1007@192.168.10.7:6090 entering state [received][100]
2012-07-02 18:48:40.519795 [DEBUG] sofia.c:5849 Remote SDP:
v=0
o=- 28405334 28661573 IN IP4 192.168.10.7
s=eyeBeam
c=IN IP4 0.0.0.0
t=0 0
m=audio 6092 RTP/AVP 8 101
a=rtpmap:8 pcma/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendonly
a=alt:1 1 : AC50E625 354B5E18 192.168.10.7 6092

2012-07-02 18:48:40.519795 [DEBUG] sofia_glue.c:3941 Looking for zrtp-hash
2012-07-02 18:48:40.519795 [DEBUG] sofia_glue.c:3919 Deciding whether to pass zrtp-hash between legs
2012-07-02 18:48:40.519795 [DEBUG] sofia_glue.c:3921 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
2012-07-02 18:48:40.519795 [DEBUG] switch_channel.c:1594 (sofia/internal/sip:1007@192.168.10.7:6090) Callstate Change ACTIVE -> HELD
2012-07-02 18:48:40.519795 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.519795 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.519795 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.539798 [DEBUG] switch_rtp.c:3527 Correct ip/port confirmed.
2012-07-02 18:48:40.539798 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute set(plivo_app=true)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 set(plivo_app=true)
2012-07-02 18:48:40.539798 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:1007@192.168.10.7:6090 SET [plivo_app]=[true]
2012-07-02 18:48:40.559794 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute set(hangup_after_bridge=false)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 set(hangup_after_bridge=false)
2012-07-02 18:48:40.559794 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:1007@192.168.10.7:6090 SET [hangup_after_bridge]=[false]
2012-07-02 18:48:40.579788 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute set(playback_sleep_val=0)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 set(playback_sleep_val=0)
2012-07-02 18:48:40.579788 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:1007@192.168.10.7:6090 SET [playback_sleep_val]=[0]
2012-07-02 18:48:40.599789 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute set(playback_terminators=none)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 set(playback_terminators=none)
2012-07-02 18:48:40.599789 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:1007@192.168.10.7:6090 SET [playback_terminators]=[none]
2012-07-02 18:48:40.619798 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute playback(/usr/local/freeswitch/sounds/ru/allopronto/welcome_allopronto.wav)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 playback(/usr/local/freeswitch/sounds/ru/allopronto/welcome_allopronto.wav)
2012-07-02 18:48:40.619798 [DEBUG] switch_ivr_play_say.c:1309 Codec Activated L16@8000hz 1 channels 20ms
2012-07-02 18:48:40.759793 [DEBUG] sofia_glue.c:3941 Looking for zrtp-hash
2012-07-02 18:48:40.759793 [DEBUG] sofia_glue.c:3919 Deciding whether to pass zrtp-hash between legs
2012-07-02 18:48:40.759793 [DEBUG] sofia_glue.c:3921 CF_ZRTP_PASSTHRU_REQ not set, so not propagating zrtp-hash
2012-07-02 18:48:40.759793 [DEBUG] sofia_glue.c:5034 Audio Codec Compare [pcma:8:8000:20:64000]/[PCMA:8:8000:20:64000]
2012-07-02 18:48:40.759793 [DEBUG] sofia_glue.c:2954 Already using PCMA
2012-07-02 18:48:40.759793 [DEBUG] sofia_glue.c:5148 Set 2833 dtmf send payload to 101
2012-07-02 18:48:40.759793 [DEBUG] sofia_glue.c:3258 Audio params changed for sofia/internal/sip:1007@192.168.10.7:6090 from 192.168.10.7:6092 to 0.0.0.0:6092
2012-07-02 18:48:40.759793 [DEBUG] sofia_glue.c:3269 AUDIO RTP [sofia/internal/sip:1007@192.168.10.7:6090] 192.168.10.151 port 18698 -> 0.0.0.0 port 6092 codec: 8 ms: 20
2012-07-02 18:48:40.759793 [DEBUG] sofia_glue.c:3310 AUDIO RTP CHANGING DEST TO: [0.0.0.0:6092]
2012-07-02 18:48:40.759793 [DEBUG] sofia.c:6371 Processing updated SDP
2012-07-02 18:48:40.759793 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.759793 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.759793 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.759793 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:40.779792 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:1007@192.168.10.7:6090 entering state [completed][200]
2012-07-02 18:48:40.779792 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:1007@192.168.10.7:6090 entering state [ready][200]
2012-07-02 18:48:43.279792 [DEBUG] switch_ivr_play_say.c:1682 done playing file /usr/local/freeswitch/sounds/ru/allopronto/welcome_allopronto.wav
2012-07-02 18:48:43.279792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:43.279792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:43.299793 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute set(playback_delimiter=!)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 set(playback_delimiter=!)
2012-07-02 18:48:43.299793 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:1007@192.168.10.7:6090 SET [playback_delimiter]=[!]
2012-07-02 18:48:43.319793 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute play_and_get_digits(1 1 3 4000 '#' 'file_string://silence_stream://1!/usr/local/freeswitch/sounds/ru/allopronto/please-press-1.wav' silence_stream://150 pagd_input ^(1)+ 4000)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 play_and_get_digits(1 1 3 4000 '#' 'file_string://silence_stream://1!/usr/local/freeswitch/sounds/ru/allopronto/please-press-1.wav' silence_stream://150 pagd_input ^(1)+ 4000)
2012-07-02 18:48:43.319793 [DEBUG] switch_ivr_play_say.c:1309 Codec Activated L16@8000hz 1 channels 20ms
2012-07-02 18:48:43.579792 [DEBUG] switch_ivr_play_say.c:1682 done playing file file_string://silence_stream://1
2012-07-02 18:48:45.899792 [DEBUG] switch_ivr_play_say.c:1682 done playing file /usr/local/freeswitch/sounds/ru/allopronto/please-press-1.wav
2012-07-02 18:48:46.559793 [DEBUG] switch_rtp.c:3728 RTP RECV DTMF 1:800
2012-07-02 18:48:46.559793 [DEBUG] switch_ivr_play_say.c:2034 Test Regex [1][^(1)+]
2012-07-02 18:48:46.599801 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:46.599801 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:46.599801 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:46.619793 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute set(playback_sleep_val=0)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 set(playback_sleep_val=0)
2012-07-02 18:48:46.619793 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:1007@192.168.10.7:6090 SET [playback_sleep_val]=[0]
2012-07-02 18:48:46.639802 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute set(playback_terminators=none)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 set(playback_terminators=none)
2012-07-02 18:48:46.639802 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:1007@192.168.10.7:6090 SET [playback_terminators]=[none]
2012-07-02 18:48:46.659794 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute playback(/usr/local/freeswitch/sounds/beep.wav)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 playback(/usr/local/freeswitch/sounds/beep.wav)
2012-07-02 18:48:46.659794 [DEBUG] switch_ivr_play_say.c:1309 Codec Activated L16@8000hz 1 channels 20ms
2012-07-02 18:48:47.099792 [DEBUG] switch_ivr_play_say.c:1682 done playing file /usr/local/freeswitch/sounds/beep.wav
2012-07-02 18:48:47.099792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:47.099792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:47.099792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:47.099792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:47.099792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:47.119793 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute set(conference_controls=none)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 set(conference_controls=none)
2012-07-02 18:48:47.119793 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:1007@192.168.10.7:6090 SET [conference_controls]=[none]
2012-07-02 18:48:47.139793 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute set(conference_max_members=200)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 set(conference_max_members=200)
2012-07-02 18:48:47.139793 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:1007@192.168.10.7:6090 SET [conference_max_members]=[200]
2012-07-02 18:48:47.159792 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute unset(conference_moh_sound)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 unset(conference_moh_sound)
2012-07-02 18:48:47.159792 [DEBUG] mod_dptools.c:1424 UNSET [conference_moh_sound]
2012-07-02 18:48:47.179792 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute set(conference_member_flags=moderator)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 set(conference_member_flags=moderator)
2012-07-02 18:48:47.179792 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:1007@192.168.10.7:6090 SET [conference_member_flags]=[moderator]
2012-07-02 18:48:47.199792 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute conference(conf-0001@plivo)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 conference(conf-0001@plivo)
2012-07-02 18:48:47.199792 [DEBUG] mod_conference.c:6288 Raw Codec Activation Success L16@8000hz 1 channel 20ms
2012-07-02 18:48:47.199792 [DEBUG] mod_conference.c:6333 Raw Codec Activation Success L16@8000hz 1 channel 20ms
2012-07-02 18:48:47.199792 [DEBUG] switch_core_codec.c:219 sofia/internal/sip:1007@192.168.10.7:6090 Push codec L16:70
2012-07-02 18:48:47.199792 [DEBUG] switch_core_session.c:778 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:47.199792 [DEBUG] mod_conference.c:3038 Setup timer soft success interval: 20 samples: 160
2012-07-02 18:48:47.199792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:47.199792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:1007@192.168.10.7:6090 [BREAK]
2012-07-02 18:48:47.219794 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute bind_digit_action(plivo_bda_638c7b6c-c45d-11e1-a0f5-f1aa4eeaf012,1,exec:event,'Event-Name=CUSTOM,Event-Subclass=conference::maintenance,Action=digits-match,Unique-ID=638c7b6c-c45d-11e1-a0f5-f1aa4eeaf012,Callback-Url=http://mydomain.com/plivo/callback?event=conference,Callback-Method=POST,Member-ID=3,Conference-Name=conf-0001,Conference-Unique-ID=d0e9218e-c45c-11e1-a0ef-f1aa4eeaf012,Digits-Match=1')
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 bind_digit_action(plivo_bda_638c7b6c-c45d-11e1-a0f5-f1aa4eeaf012,1,exec:event,'Event-Name=CUSTOM,Event-Subclass=conference::maintenance,Action=digits-match,Unique-ID=638c7b6c-c45d-11e1-a0f5-f1aa4eeaf012,Callback-Url=http://mydomain.com/plivo/callback?event=conference,Callback-Method=POST,Member-ID=3,Conference-Name=conf-0001,Conference-Unique-ID=d0e9218e-c45c-11e1-a0ef-f1aa4eeaf012,Digits-Match=1')
2012-07-02 18:48:47.219794 [INFO] switch_ivr_async.c:194 Digit parser DPTOOLS: Setting realm to 'plivo_bda_638c7b6c-c45d-11e1-a0f5-f1aa4eeaf012'
2012-07-02 18:48:47.219794 [DEBUG] switch_ivr_async.c:288 Digit parser DPTOOLS: binding 1/plivo_bda_638c7b6c-c45d-11e1-a0f5-f1aa4eeaf012/0 callback: 0x7f970181cf00 data: 0xcc6318
2012-07-02 18:48:47.219794 [DEBUG] switch_ivr.c:598 sofia/internal/sip:1007@192.168.10.7:6090 Command Execute digit_action_set_realm(plivo_bda_638c7b6c-c45d-11e1-a0f5-f1aa4eeaf012)
EXECUTE sofia/internal/sip:1007@192.168.10.7:6090 digit_action_set_realm(plivo_bda_638c7b6c-c45d-11e1-a0f5-f1aa4eeaf012)
2012-07-02 18:48:47.219794 [INFO] switch_ivr_async.c:194 Digit parser DPTOOLS: Setting realm to 'plivo_bda_638c7b6c-c45d-11e1-a0f5-f1aa4eeaf012'
2012-07-02 18:48:50.139792 [DEBUG] switch_rtp.c:3728 RTP RECV DTMF 1:800
2012-07-02 18:48:50.139792 [ERR] switch_ivr_async.c:547 dmachine overflow error!
2012-07-02 18:48:50.939792 [DEBUG] switch_rtp.c:3728 RTP RECV DTMF 1:960
2012-07-02 18:48:50.939792 [ERR] switch_ivr_async.c:547 dmachine overflow error!
@mike-plivo
Copy link
Member

right, looks like its related to some changes in freeswitch, will look

@Syfer
Copy link
Author

Syfer commented Jul 12, 2012

ok. I'll wait.
Any progress ?

@WizADSL
Copy link

WizADSL commented Jan 24, 2013

Has anyone been able to resolve this yet? I'm willing to help but I don't know what this looks like when is DOES work so I can't figure out where to start. I last tested this with FS version built from source on 01/22/13

@mike-plivo
Copy link
Member

it is related to this change : http://jira.freeswitch.org/browse/FS-4297
But if we use uuid_transfer we break the plivo call (socket application) .

@theamit-dev
Copy link

Is there any fix for this ....

@WizADSL
Copy link

WizADSL commented Jan 31, 2013

Tamiel, I'm trying to get to a commit point in the source where this worked for plivo. I'm basically jumping backwards trough the commits trying to find a version without this problem but have failed so far. Do you happen to know how far back I need to go?

@mike-plivo
Copy link
Member

Hi WizADSL,

the issue is not in Plivo itself . There is a change in Freeswitch which disable use of the digit realm binding feature while a send_msg eventsocket command or an application from dptools is executed and still running :
if you try freeswitch git version 8e47f3c660276bc653f6cb1ac2611d5345244bd9 , it should work (it's an old version)

@WizADSL
Copy link

WizADSL commented Feb 1, 2013

Thanks, I just tried the version you suggested and the feature works again (GREAT!), but now if the aleg disconnects, plivo does not catch that the call ended. it just sits at "wait for action start"

@mike-plivo
Copy link
Member

if you have plivo logs and freeswitch debug logs, we can check this issue

@WizADSL
Copy link

WizADSL commented Feb 1, 2013

Thanks so much for taking a look. The plivo log is at http://pastebin.com/VVk1Zk29 and the freeswitch log is at http://pastebin.com/i6nGydRW . You'll see some unusual output in the plivo debug log because I have added the ability to maintain cookies for the duration of the call for any http requests made during the call. I've added a few other things but I don't think they are in this log. I imagine you suspect my changes may have caused the problem, but I don't think so because on the newer freeswitch version where dtmf is a problem the disconnects are handled properly. Thanks again for your help.

@theamit-dev
Copy link

That worked great. But console still shows the dmachine overflow error. But actually DTMF works

@WizADSL
Copy link

WizADSL commented Feb 20, 2013

Tamiel, Not meaning to rush, but have you had a chance to take a look at the logs?

@mike-plivo
Copy link
Member

can you try last git version ?

@csik
Copy link

csik commented Jun 11, 2014

Hi Tamiel,
Using the latest Plivo and a more current version of Freeswitch, conference does not respond to digits. Is there any plan to make plivo-framework work with contemporary versions of Freeswitch?

To confirm, as those above noted, rev 8e47f3c of Freeswitch does seem to work. It is no longer hosted at github, however; see:
https://fisheye.freeswitch.org/changelog/FreeSWITCH?cs=8e47f3c660276bc653f6cb1ac2611d5345244bd9

2014-06-11 22:51:04.452183 [DEBUG] switch_ivr.c:612 sofia/external/6176424223 Command Execute bind_digit_action(plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2,#9,exec:event,'Event-Name=CUSTOM,Event-Subclass=conference::maintenance,Action=digits-match,Unique-ID=d75960b4-f1ba-11e3-b5f7-7d992c822fd2,Callback-Url=http://127.0.0.1:5000/confer_events/,Callback-Method=POST,Member-ID=5,Conference-Name=plivo,Conference-Unique-ID=de20cd74-f1ba-11e3-b602-7d992c822fd2,Digits-Match=#9')
EXECUTE sofia/external/6176424223 bind_digit_action(plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2,#9,exec:event,'Event-Name=CUSTOM,Event-Subclass=conference::maintenance,Action=digits-match,Unique-ID=d75960b4-f1ba-11e3-b5f7-7d992c822fd2,Callback-Url=http://127.0.0.1:5000/confer_events/,Callback-Method=POST,Member-ID=5,Conference-Name=plivo,Conference-Unique-ID=de20cd74-f1ba-11e3-b602-7d992c822fd2,Digits-Match=#9')
2014-06-11 22:51:04.452183 [INFO] switch_ivr_async.c:212 Digit parser DPTOOLS: Setting realm to 'plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2'
2014-06-11 22:51:04.452183 [DEBUG] switch_ivr_async.c:321 Digit parser DPTOOLS: binding #9/plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2/0 callback: 0x7fd75b59f910 data: 0x7fd6fc109bc0
2014-06-11 22:51:04.452183 [DEBUG] switch_ivr.c:612 sofia/external/6176424223 Command Execute bind_digit_action(plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2,#7,exec:event,'Event-Name=CUSTOM,Event-Subclass=conference::maintenance,Action=digits-match,Unique-ID=d75960b4-f1ba-11e3-b5f7-7d992c822fd2,Callback-Url=http://127.0.0.1:5000/confer_events/,Callback-Method=POST,Member-ID=5,Conference-Name=plivo,Conference-Unique-ID=de20cd74-f1ba-11e3-b602-7d992c822fd2,Digits-Match=#7')
EXECUTE sofia/external/6176424223 bind_digit_action(plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2,#7,exec:event,'Event-Name=CUSTOM,Event-Subclass=conference::maintenance,Action=digits-match,Unique-ID=d75960b4-f1ba-11e3-b5f7-7d992c822fd2,Callback-Url=http://127.0.0.1:5000/confer_events/,Callback-Method=POST,Member-ID=5,Conference-Name=plivo,Conference-Unique-ID=de20cd74-f1ba-11e3-b602-7d992c822fd2,Digits-Match=#7')
2014-06-11 22:51:04.452183 [DEBUG] switch_ivr_async.c:321 Digit parser DPTOOLS: binding #7/plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2/0 callback: 0x7fd75b59f910 data: 0x7fd6fc10a0f8
2014-06-11 22:51:04.452183 [DEBUG] switch_ivr.c:612 sofia/external/6176424223 Command Execute bind_digit_action(plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2,#8,exec:event,'Event-Name=CUSTOM,Event-Subclass=conference::maintenance,Action=digits-match,Unique-ID=d75960b4-f1ba-11e3-b5f7-7d992c822fd2,Callback-Url=http://127.0.0.1:5000/confer_events/,Callback-Method=POST,Member-ID=5,Conference-Name=plivo,Conference-Unique-ID=de20cd74-f1ba-11e3-b602-7d992c822fd2,Digits-Match=#8')
EXECUTE sofia/external/6176424223 bind_digit_action(plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2,#8,exec:event,'Event-Name=CUSTOM,Event-Subclass=conference::maintenance,Action=digits-match,Unique-ID=d75960b4-f1ba-11e3-b5f7-7d992c822fd2,Callback-Url=http://127.0.0.1:5000/confer_events/,Callback-Method=POST,Member-ID=5,Conference-Name=plivo,Conference-Unique-ID=de20cd74-f1ba-11e3-b602-7d992c822fd2,Digits-Match=#8')
2014-06-11 22:51:04.452183 [DEBUG] switch_ivr_async.c:321 Digit parser DPTOOLS: binding #8/plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2/0 callback: 0x7fd75b59f910 data: 0x7fd6fc10a630
2014-06-11 22:51:04.452183 [DEBUG] switch_ivr.c:612 sofia/external/6176424223 Command Execute bind_digit_action(plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2,,exec:event,'Event-Name=CUSTOM,Event-Subclass=conference::maintenance,Action=kick,Unique-ID=d75960b4-f1ba-11e3-b5f7-7d992c822fd2,Member-ID=5,Conference-Name=plivo,Conference-Unique-ID=de20cd74-f1ba-11e3-b602-7d992c822fd2')
EXECUTE sofia/external/6176424223 bind_digit_action(plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2,,exec:event,'Event-Name=CUSTOM,Event-Subclass=conference::maintenance,Action=kick,Unique-ID=d75960b4-f1ba-11e3-b5f7-7d992c822fd2,Member-ID=5,Conference-Name=plivo,Conference-Unique-ID=de20cd74-f1ba-11e3-b602-7d992c822fd2')
2014-06-11 22:51:04.452183 [DEBUG] switch_ivr_async.c:321 Digit parser DPTOOLS: binding */plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2/0 callback: 0x7fd75b59f910 data: 0x7fd6fc0a6350
2014-06-11 22:51:04.452183 [DEBUG] switch_ivr.c:612 sofia/external/6176424223 Command Execute digit_action_set_realm(plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2)
EXECUTE sofia/external/6176424223 digit_action_set_realm(plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2)
2014-06-11 22:51:04.452183 [INFO] switch_ivr_async.c:212 Digit parser DPTOOLS: Setting realm to 'plivo_bda_d75960b4-f1ba-11e3-b5f7-7d992c822fd2'
2014-06-11 22:51:11.432165 [DEBUG] switch_rtp.c:4910 RTP RECV DTMF #:1640
2014-06-11 22:51:11.432165 [DEBUG] switch_channel.c:468 RECV DTMF #:1640
2014-06-11 22:51:11.892171 [DEBUG] switch_rtp.c:4910 RTP RECV DTMF 9:1400
2014-06-11 22:51:11.892171 [DEBUG] switch_channel.c:468 RECV DTMF 9:1400

.... nothing shows up via Plivo
2014-06-11 22:52:09.192164 [DEBUG] switch_core_session.c:1006 Send signal sofia/external/6176424223 [BREAK]
2014-06-11 22:52:09.212175 [NOTICE] sofia.c:715 Hangup sofia/external/6176424223 [CS_EXECUTE] [NORMAL_CLEARING]
2014-06-11 22:52:09.212175 [DEBUG] switch_channel.c:3129 Send signal sofia/external/6176424223 [KILL]
2014-06-11 22:52:09.212175 [DEBUG] switch_core_session.c:1341 Send signal sofia/external/6176424223 [BREAK]
2014-06-11 22:52:09.212175 [DEBUG] mod_conference.c:3848 Channel leaving conference, cause: NORMAL_CLEARING
2014-06-11 22:52:09.212175 [DEBUG] mod_event_socket.c:1355 sofia/external/6176424223 Socket Linger 0

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@mike-plivo @Syfer @csik @theamit-dev @WizADSL