plivoframework icon indicating copy to clipboard operation
plivoframework copied to clipboard

Published 20 hours ago • verified publisher icon plivo

No DTMF in conference

Open Syfer opened this issue 13 years ago • 14 comments

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]=[[email protected]] 2012-07-02 18:48:37.879793 [NOTICE] switch_channel.c:926 New Channel sofia/internal/sip:[email protected]:6090 [638c7b6c-c45d-11e1-a0f5-f1aa4eeaf012] 2012-07-02 18:48:37.879793 [DEBUG] mod_sofia.c:4775 (sofia/internal/sip:[email protected]: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:[email protected]:6090 [BREAK] 2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:[email protected]:6090) Running State Change CS_INIT 2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/sip:[email protected]:6090) State INIT 2012-07-02 18:48:37.879793 [DEBUG] mod_sofia.c:85 sofia/internal/sip:[email protected]: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:[email protected]: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:[email protected]:6090 [BREAK] 2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:424 (sofia/internal/sip:[email protected]:6090) State INIT going to sleep 2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:[email protected]:6090) Running State Change CS_ROUTING 2012-07-02 18:48:37.879793 [DEBUG] switch_channel.c:1919 (sofia/internal/sip:[email protected]:6090) Callstate Change DOWN -> RINGING 2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/sip:[email protected]:6090) State ROUTING 2012-07-02 18:48:37.879793 [DEBUG] mod_sofia.c:148 sofia/internal/sip:[email protected]:6090 SOFIA ROUTING 2012-07-02 18:48:37.879793 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sip:[email protected]: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:[email protected]:6090 [BREAK] 2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:433 (sofia/internal/sip:[email protected]:6090) State ROUTING going to sleep 2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:[email protected]:6090) Running State Change CS_CONSUME_MEDIA 2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:452 (sofia/internal/sip:[email protected]:6090) State CONSUME_MEDIA 2012-07-02 18:48:37.879793 [DEBUG] switch_core_state_machine.c:452 (sofia/internal/sip:[email protected]: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:[email protected]:6090 [BREAK] 2012-07-02 18:48:37.879793 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:[email protected]:6090 entering state [calling][0] 2012-07-02 18:48:37.979792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:37.979792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:37.979792 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:[email protected]:6090 entering state [proceeding][180] 2012-07-02 18:48:37.979792 [NOTICE] sofia.c:5930 Ring-Ready sofia/internal/sip:[email protected]:6090! 2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.499792 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:[email protected]: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:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.499792 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:[email protected]: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:[email protected]: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:[email protected]: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:[email protected]: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:[email protected]:6090 Set rtp dtmf delay to 40 2012-07-02 18:48:40.499792 [DEBUG] switch_channel.c:3301 (sofia/internal/sip:[email protected]:6090) Callstate Change RINGING -> ACTIVE 2012-07-02 18:48:40.499792 [NOTICE] sofia.c:6573 Channel [sofia/internal/sip:[email protected]:6090] has been answered 2012-07-02 18:48:40.499792 [DEBUG] switch_ivr_originate.c:3341 Originate Resulted in Success: [sofia/internal/sip:[email protected]:6090] 2012-07-02 18:48:40.499792 [DEBUG] switch_ivr_originate.c:3341 Originate Resulted in Success: [sofia/internal/sip:[email protected]:6090] 2012-07-02 18:48:40.499792 [INFO] switch_channel.c:2761 sofia/internal/sip:[email protected]:6090 Flipping CID from "" <PlivoCaller> to "Outbound Call" <1007> 2012-07-02 18:48:40.499792 [DEBUG] mod_commands.c:3616 (sofia/internal/sip:[email protected]: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:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.499792 [DEBUG] switch_core_state_machine.c:385 (sofia/internal/sip:[email protected]:6090) Running State Change CS_EXECUTE 2012-07-02 18:48:40.499792 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/sip:[email protected]:6090) State EXECUTE 2012-07-02 18:48:40.499792 [DEBUG] mod_sofia.c:241 sofia/internal/sip:[email protected]:6090 SOFIA EXECUTE 2012-07-02 18:48:40.499792 [DEBUG] switch_core_state_machine.c:196 sofia/internal/sip:[email protected]:6090 Standard EXECUTE EXECUTE sofia/internal/sip:[email protected]: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:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.499792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.519795 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:[email protected]: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:[email protected]:6090) Callstate Change ACTIVE -> HELD 2012-07-02 18:48:40.519795 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.519795 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.519795 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:[email protected]: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:[email protected]:6090 Command Execute set(plivo_app=true) EXECUTE sofia/internal/sip:[email protected]:6090 set(plivo_app=true) 2012-07-02 18:48:40.539798 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:[email protected]:6090 SET [plivo_app]=[true] 2012-07-02 18:48:40.559794 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]:6090 Command Execute set(hangup_after_bridge=false) EXECUTE sofia/internal/sip:[email protected]:6090 set(hangup_after_bridge=false) 2012-07-02 18:48:40.559794 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:[email protected]:6090 SET [hangup_after_bridge]=[false] 2012-07-02 18:48:40.579788 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]:6090 Command Execute set(playback_sleep_val=0) EXECUTE sofia/internal/sip:[email protected]:6090 set(playback_sleep_val=0) 2012-07-02 18:48:40.579788 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:[email protected]:6090 SET [playback_sleep_val]=[0] 2012-07-02 18:48:40.599789 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]:6090 Command Execute set(playback_terminators=none) EXECUTE sofia/internal/sip:[email protected]:6090 set(playback_terminators=none) 2012-07-02 18:48:40.599789 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:[email protected]:6090 SET [playback_terminators]=[none] 2012-07-02 18:48:40.619798 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]:6090 Command Execute playback(/usr/local/freeswitch/sounds/ru/allopronto/welcome_allopronto.wav) EXECUTE sofia/internal/sip:[email protected]: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:[email protected]: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:[email protected]: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:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.759793 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.759793 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.759793 [DEBUG] switch_core_session.c:924 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:40.779792 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:[email protected]:6090 entering state [completed][200] 2012-07-02 18:48:40.779792 [DEBUG] sofia.c:5838 Channel sofia/internal/sip:[email protected]: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:[email protected]:6090 [BREAK] 2012-07-02 18:48:43.279792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:43.299793 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]:6090 Command Execute set(playback_delimiter=!) EXECUTE sofia/internal/sip:[email protected]:6090 set(playback_delimiter=!) 2012-07-02 18:48:43.299793 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:[email protected]:6090 SET [playback_delimiter]=[!] 2012-07-02 18:48:43.319793 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]: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:[email protected]: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:[email protected]:6090 [BREAK] 2012-07-02 18:48:46.599801 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:46.599801 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:46.619793 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]:6090 Command Execute set(playback_sleep_val=0) EXECUTE sofia/internal/sip:[email protected]:6090 set(playback_sleep_val=0) 2012-07-02 18:48:46.619793 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:[email protected]:6090 SET [playback_sleep_val]=[0] 2012-07-02 18:48:46.639802 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]:6090 Command Execute set(playback_terminators=none) EXECUTE sofia/internal/sip:[email protected]:6090 set(playback_terminators=none) 2012-07-02 18:48:46.639802 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:[email protected]:6090 SET [playback_terminators]=[none] 2012-07-02 18:48:46.659794 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]:6090 Command Execute playback(/usr/local/freeswitch/sounds/beep.wav) EXECUTE sofia/internal/sip:[email protected]: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:[email protected]:6090 [BREAK] 2012-07-02 18:48:47.099792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:47.099792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:47.099792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:47.099792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:47.119793 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]:6090 Command Execute set(conference_controls=none) EXECUTE sofia/internal/sip:[email protected]:6090 set(conference_controls=none) 2012-07-02 18:48:47.119793 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:[email protected]:6090 SET [conference_controls]=[none] 2012-07-02 18:48:47.139793 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]:6090 Command Execute set(conference_max_members=200) EXECUTE sofia/internal/sip:[email protected]:6090 set(conference_max_members=200) 2012-07-02 18:48:47.139793 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:[email protected]:6090 SET [conference_max_members]=[200] 2012-07-02 18:48:47.159792 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]:6090 Command Execute unset(conference_moh_sound) EXECUTE sofia/internal/sip:[email protected]: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:[email protected]:6090 Command Execute set(conference_member_flags=moderator) EXECUTE sofia/internal/sip:[email protected]:6090 set(conference_member_flags=moderator) 2012-07-02 18:48:47.179792 [DEBUG] mod_dptools.c:1307 sofia/internal/sip:[email protected]:6090 SET [conference_member_flags]=[moderator] 2012-07-02 18:48:47.199792 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]:6090 Command Execute conference(conf-0001@plivo) EXECUTE sofia/internal/sip:[email protected]: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:[email protected]:6090 Push codec L16:70 2012-07-02 18:48:47.199792 [DEBUG] switch_core_session.c:778 Send signal sofia/internal/sip:[email protected]: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:[email protected]:6090 [BREAK] 2012-07-02 18:48:47.199792 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/sip:[email protected]:6090 [BREAK] 2012-07-02 18:48:47.219794 [DEBUG] switch_ivr.c:598 sofia/internal/sip:[email protected]: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:[email protected]: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:[email protected]:6090 Command Execute digit_action_set_realm(plivo_bda_638c7b6c-c45d-11e1-a0f5-f1aa4eeaf012) EXECUTE sofia/internal/sip:[email protected]: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!

Syfer avatar Jul 02 '12 15:07 Syfer

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

mike-plivo avatar Jul 09 '12 21:07 mike-plivo

ok. I'll wait. Any progress ?

Syfer avatar Jul 12 '12 07:07 Syfer

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

WizADSL avatar Jan 24 '13 14:01 WizADSL

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) .

mike-plivo avatar Jan 26 '13 03:01 mike-plivo

Is there any fix for this ....

theamit-dev avatar Jan 29 '13 05:01 theamit-dev

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?

WizADSL avatar Jan 31 '13 19:01 WizADSL

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)

mike-plivo avatar Jan 31 '13 20:01 mike-plivo

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"

WizADSL avatar Feb 01 '13 00:02 WizADSL

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

mike-plivo avatar Feb 01 '13 01:02 mike-plivo

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.

WizADSL avatar Feb 01 '13 06:02 WizADSL

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

theamit-dev avatar Feb 04 '13 03:02 theamit-dev

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

WizADSL avatar Feb 20 '13 23:02 WizADSL

can you try last git version ?

mike-plivo avatar Mar 20 '13 11:03 mike-plivo

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

csik avatar Jun 11 '14 23:06 csik