Sure. Im sending a pcap file made by tcpdump and one that i made by ngrep. In both files, it was registering whats happening when i stuck the channel by hanging up while using a ESL connection inside a conference(app socket 8085 sync full). I did a "conference kick" command in this channel while its was waiting to close the ESL connection. 2011/5/16 Michael Collins <msc@freeswitch.org>
Can you tcpdump or otherwise capture the traffic on port 8085? I am curious what is happening with that. -MC
On Mon, May 16, 2011 at 12:12 PM, Leonardo P. Bidinoto < leonardo.bidinoto@voicetechnology.com.br> wrote:
hehe, ok michael.
here is the pastebin link: http://pastebin.freeswitch.org/16303
2011/5/13 Michael Collins <msc@freeswitch.org>
Pastebin this info and select "FreeSWITCH Log" as the syntax highlighting. I need the colorized output to read logs. (I'm getting older and it's hard for me to ready black and white in an email.)
-MC
On Fri, May 13, 2011 at 7:32 AM, Leonardo P. Bidinoto < leonardo.bidinoto@voicetechnology.com.br> wrote:
Hi Michael,
Just succeeded to reproduce the problem.
The condition is: when a channel inside a conference is using a ESL connection(lets call it "A") through socket application and another ESL connection(lets call it "B") executes a command with this channel, the "B" ESL connection will wait the "A" ESL connection close to execute its command. If the channel hangs up before the "A" ESL connection is closed, then "B" ESL command will never be executed and the stucked channel will still be there, into sofia and the conference too. To verify that, just do "show channels" and "conference list". with "uuid_exists" command, return "false".
Here are the actions done by the channel before get stucked:
16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.187321 [NOTICE] switch_channel.c:816 New Channel sofia/external/ 1000123402@192.168.0.154 [16e09413-9cb0-4011-a635-f91933a35c0f] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] sofia.c:4761 Channel sofia/external/1000123402@192.168.0.154 entering state [received][100] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] sofia.c:4772 Remote SDP: 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] sofia_glue.c:4656 Audio Codec Compare [BV32:107:16000:20:0]/[PCMU:0:8000:20:64000] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] sofia_glue.c:4656 Audio Codec Compare [BV32:107:16000:20:0]/[PCMA:8:8000:20:64000] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] sofia_glue.c:4656 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] sofia_glue.c:2788 Set Codec sofia/external/1000123402@192.168.0.154PCMU/8000 20 ms 160 samples 64000 bits 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] sofia_glue.c:4770 Set 2833 dtmf send/recv payload to 101 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] sofia.c:4943 (sofia/external/1000123402@192.168.0.154) State Change CS_NEW -> CS_INIT 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] switch_core_session.c:1114 Send signal sofia/external/ 1000123402@192.168.0.154 [BREAK] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] switch_core_state_machine.c:325 (sofia/external/ 1000123402@192.168.0.154) Running State Change CS_INIT 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] switch_core_state_machine.c:361 (sofia/external/ 1000123402@192.168.0.154) State INIT 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] mod_sofia.c:84 sofia/external/1000123402@192.168.0.154 SOFIA INIT 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] mod_sofia.c:124 (sofia/external/1000123402@192.168.0.154) State Change CS_INIT -> CS_ROUTING 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] switch_core_session.c:1114 Send signal sofia/external/ 1000123402@192.168.0.154 [BREAK] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] switch_core_state_machine.c:361 (sofia/external/ 1000123402@192.168.0.154) State INIT going to sleep 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] switch_core_state_machine.c:325 (sofia/external/ 1000123402@192.168.0.154) Running State Change CS_ROUTING 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] switch_channel.c:1665 (sofia/external/1000123402@192.168.0.154) Callstate Change DOWN -> RINGING 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] switch_core_state_machine.c:364 (sofia/external/ 1000123402@192.168.0.154) State ROUTING 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] mod_sofia.c:147 sofia/external/1000123402@192.168.0.154 SOFIA ROUTING 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [DEBUG] switch_core_state_machine.c:77 sofia/external/1000123402@192.168.0.154Standard ROUTING 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.188323 [INFO] mod_dialplan_xml.c:331 Processing Phone1 <1000123402>->1234567890 in context public 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/ 1000123402@192.168.0.154 parsing [public->unloop] continue=false 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/ 1000123402@192.168.0.154 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/ 1000123402@192.168.0.154 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/ 1000123402@192.168.0.154 parsing [public->public_extensions] continue=false 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/ 1000123402@192.168.0.154 Regex (PASS) [public_extensions] destination_number(1234567890) =~ /^(\d*)$/ break=on-false 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/ 1000123402@192.168.0.154 Action transfer(1234567890 XML default) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.190328 [DEBUG] switch_core_state_machine.c:119 (sofia/external/ 1000123402@192.168.0.154) State Change CS_ROUTING -> CS_EXECUTE 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.190328 [DEBUG] switch_core_session.c:1114 Send signal sofia/external/ 1000123402@192.168.0.154 [BREAK] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.190328 [DEBUG] switch_core_state_machine.c:364 (sofia/external/ 1000123402@192.168.0.154) State ROUTING going to sleep 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.190328 [DEBUG] switch_core_state_machine.c:325 (sofia/external/ 1000123402@192.168.0.154) Running State Change CS_EXECUTE 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.190328 [DEBUG] switch_core_state_machine.c:371 (sofia/external/ 1000123402@192.168.0.154) State EXECUTE 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.190328 [DEBUG] mod_sofia.c:240 sofia/external/1000123402@192.168.0.154 SOFIA EXECUTE 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.191327 [DEBUG] switch_core_state_machine.c:157 sofia/external/1000123402@192.168.0.154Standard EXECUTE 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 transfer(1234567890 XML default) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.191327 [DEBUG] switch_ivr.c:1597 (sofia/external/1000123402@192.168.0.154) State Change CS_EXECUTE -> CS_ROUTING 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.191327 [DEBUG] switch_core_session.c:1114 Send signal sofia/external/ 1000123402@192.168.0.154 [BREAK] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.191327 [DEBUG] switch_core_session.c:707 Send signal sofia/external/ 1000123402@192.168.0.154 [BREAK] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.191327 [NOTICE] switch_ivr.c:1603 Transfer sofia/external/1000123402@192.168.0.154 to XML[1234567890@default] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.191327 [DEBUG] switch_core_state_machine.c:371 (sofia/external/ 1000123402@192.168.0.154) State EXECUTE going to sleep 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.191327 [DEBUG] switch_core_state_machine.c:325 (sofia/external/ 1000123402@192.168.0.154) Running State Change CS_ROUTING 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.191327 [DEBUG] switch_core_state_machine.c:364 (sofia/external/ 1000123402@192.168.0.154) State ROUTING 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.191327 [DEBUG] mod_sofia.c:147 sofia/external/1000123402@192.168.0.154 SOFIA ROUTING 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.191327 [DEBUG] switch_core_state_machine.c:77 sofia/external/1000123402@192.168.0.154Standard ROUTING 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.191327 [INFO] mod_dialplan_xml.c:331 Processing Phone1 <1000123402>->1234567890 in context default 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/ 1000123402@192.168.0.154 parsing [default->flex] continue=false 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/ 1000123402@192.168.0.154 Regex (PASS) [flex] destination_number(1234567890) =~ /^(\d+)$/ break=on-false 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/ 1000123402@192.168.0.154 Action log(INFO VOICE received dest=1234567890) 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/ 1000123402@192.168.0.154 Action set(playback_terminators=#) 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/ 1000123402@192.168.0.154 Action log(INFO Let's do some ivrd, shall we?)
16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/ 1000123402@192.168.0.154 Action set(ivr_path=/usr/local/ipconf/fs/daemon/ivr.rb) 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/ 1000123402@192.168.0.154 Action socket(localhost:8084 full) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.193325 [DEBUG] switch_core_state_machine.c:119 (sofia/external/ 1000123402@192.168.0.154) State Change CS_ROUTING -> CS_EXECUTE 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.193325 [DEBUG] switch_core_session.c:1114 Send signal sofia/external/ 1000123402@192.168.0.154 [BREAK] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.193325 [DEBUG] switch_core_state_machine.c:364 (sofia/external/ 1000123402@192.168.0.154) State ROUTING going to sleep 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.193325 [DEBUG] switch_core_state_machine.c:325 (sofia/external/ 1000123402@192.168.0.154) Running State Change CS_EXECUTE 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.193325 [DEBUG] switch_core_state_machine.c:371 (sofia/external/ 1000123402@192.168.0.154) State EXECUTE 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.193325 [DEBUG] mod_sofia.c:240 sofia/external/1000123402@192.168.0.154 SOFIA EXECUTE 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.193325 [DEBUG] switch_core_state_machine.c:157 sofia/external/1000123402@192.168.0.154Standard EXECUTE 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 log(INFO VOICE received dest=1234567890) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.193325 [INFO] mod_dptools.c:1184 VOICE received dest=1234567890 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 set(playback_terminators=#) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.194331 [DEBUG] mod_dptools.c:1060 sofia/external/1000123402@192.168.0.154 SET [playback_terminators]=[#] 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 log(INFO Let's do some ivrd, shall we?) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.194331 [INFO] mod_dptools.c:1184 Let's do some ivrd, shall we? 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154set(ivr_path=/usr/local/ipconf/fs/daemon/ivr.rb) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.194331 [DEBUG] mod_dptools.c:1060 sofia/external/1000123402@192.168.0.154 SET [ivr_path]=[/usr/local/ipconf/fs/daemon/ivr.rb] 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 socket(localhost:8084 full) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.930309 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute answer() 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 answer() 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.930309 [DEBUG] sofia_glue.c:3022 AUDIO RTP [sofia/external/1000123402@192.168.0.154] 192.168.0.154 port 24232 -> 192.168.0.111 port 4046 codec: 0 ms: 20 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.930309 [DEBUG] switch_rtp.c:1623 Starting timer [soft] 160 bytes per 20ms 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.932313 [DEBUG] sofia_glue.c:3284 Set 2833 dtmf send payload to 101 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.932313 [DEBUG] sofia_glue.c:3289 Set 2833 dtmf receive payload to 101 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.932313 [DEBUG] mod_sofia.c:681 Local SDP sofia/external/1000123402@192.168.0.154: 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.932313 [DEBUG] switch_core_session.c:707 Send signal sofia/external/ 1000123402@192.168.0.154 [BREAK] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.932313 [DEBUG] switch_channel.c:2827 (sofia/external/1000123402@192.168.0.154) Callstate Change RINGING -> ACTIVE 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.932313 [NOTICE] mod_dptools.c:930 Channel [sofia/external/1000123402@192.168.0.154] has been answered 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.933312 [DEBUG] sofia.c:4761 Channel sofia/external/1000123402@192.168.0.154 entering state [completed][200] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:48.040285 [DEBUG] sofia.c:4761 Channel sofia/external/1000123402@192.168.0.154 entering state [ready][200] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:48.082294 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute playback(/usr/local/freeswitch/sounds/flex/app32/teste/WelcomeToTheConferenceSystem.wav) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154playback(/usr/local/freeswitch/sounds/flex/app32/teste/WelcomeToTheConferenceSystem.wav) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:48.082294 [DEBUG] switch_ivr_play_say.c:1279 Codec Activated L16@8000hz 1 channels 20ms 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:48.114277 [DEBUG] switch_ivr_play_say.c:1649 done playing file 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:48.155281 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute read(1 1 /usr/local/freeswitch/sounds/flex/app32/teste/Mainmenu.wav flex_digits 5000 ) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 read(1 1 /usr/local/freeswitch/sounds/flex/app32/teste/Mainmenu.wav flex_digits 5000 ) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:48.155281 [DEBUG] switch_ivr_play_say.c:1279 Codec Activated L16@8000hz 1 channels 20ms 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:00.893670 [DEBUG] switch_rtp.c:3280 RTP RECV DTMF 1:1120 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:00.893670 [DEBUG] switch_ivr_play_say.c:1649 done playing file 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:00.897674 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute set(flex_digits) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 set(flex_digits) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:00.897674 [DEBUG] mod_dptools.c:1060 sofia/external/1000123402@192.168.0.154 SET [flex_digits]=[UNDEF] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:00.940673 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute read(1 1 /usr/local/freeswitch/sounds/flex/app32/teste/PleaseEnterYourPassCodeNow.wav flex_digits 5000 ) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 read(1 1 /usr/local/freeswitch/sounds/flex/app32/teste/PleaseEnterYourPassCodeNow.wav flex_digits 5000 ) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:00.940673 [DEBUG] switch_ivr_play_say.c:1279 Codec Activated L16@8000hz 1 channels 20ms 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:01.113662 [DEBUG] switch_rtp.c:3280 RTP RECV DTMF 8:640 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:01.113662 [DEBUG] switch_ivr_play_say.c:1649 done playing file 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:01.116663 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute set(flex_digits) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 set(flex_digits) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:01.116663 [DEBUG] mod_dptools.c:1060 sofia/external/1000123402@192.168.0.154 SET [flex_digits]=[UNDEF] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:01.117663 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute read(1 11 /usr/local/freeswitch/sounds/flex/app32/teste/Silence.wav flex_digits 5000 #,*) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 read(1 11 /usr/local/freeswitch/sounds/flex/app32/teste/Silence.wav flex_digits 5000 #,*) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:01.117663 [DEBUG] switch_ivr_play_say.c:1279 Codec Activated L16@8000hz 1 channels 20ms 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:01.153658 [DEBUG] switch_ivr_play_say.c:1649 done playing file 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:02.053615 [DEBUG] switch_rtp.c:3280 RTP RECV DTMF #:960 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:02.055618 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute set(flex_digits) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 set(flex_digits) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:02.055618 [DEBUG] mod_dptools.c:1060 sofia/external/1000123402@192.168.0.154 SET [flex_digits]=[UNDEF] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:02.146613 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute playback(/usr/local/freeswitch/sounds/flex/app32/teste/InternalHelp.wav) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154playback(/usr/local/freeswitch/sounds/flex/app32/teste/InternalHelp.wav) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:02.146613 [DEBUG] switch_ivr_play_say.c:1279 Codec Activated L16@8000hz 1 channels 20ms 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:02.333603 [DEBUG] switch_rtp.c:3280 RTP RECV DTMF #:800 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:02.333603 [DEBUG] mod_dptools.c:1664 Digit # 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:02.333603 [DEBUG] switch_ivr_play_say.c:1649 done playing file 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:02.350617 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute playback(/usr/local/freeswitch/sounds/flex/app32/teste/YouAreTheOnlyPersonOnThisConference.wav) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154playback(/usr/local/freeswitch/sounds/flex/app32/teste/YouAreTheOnlyPersonOnThisConference.wav) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:02.350617 [DEBUG] switch_ivr_play_say.c:1279 Codec Activated L16@8000hz 1 channels 20ms 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:04.253520 [DEBUG] switch_ivr_play_say.c:1649 done playing file 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:04.322510 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute conference(15646@teste+flags{waste}) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 conference(15646@teste+flags{waste}) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:04.813492 [DEBUG] mod_conference.c:5582 Raw Codec Activation Success L16@8000hz 1 channel 20ms 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:04.813492 [DEBUG] mod_conference.c:5627 Raw Codec Activation Success L16@8000hz 1 channel 20ms 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:04.813492 [DEBUG] switch_core_codec.c:116 sofia/external/1000123402@192.168.0.154 Push codec L16:70 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:05.280469 [DEBUG] switch_core_session.c:707 Send signal sofia/external/ 1000123402@192.168.0.154 [BREAK] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:05.280469 [DEBUG] mod_conference.c:2557 Setup timer soft success interval: 20 samples: 160 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:16.573928 [DEBUG] switch_rtp.c:3280 RTP RECV DTMF *:960 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:16.593929 [DEBUG] mod_conference.c:2021 Execute app: socket, localhost:8085 sync full 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:16.593929 [DEBUG] switch_core_codec.c:141 sofia/external/1000123402@192.168.0.154 Restore previous codec PCMU:0. 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 socket(localhost:8085 sync full) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:17.097927 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute read(1 1 /usr/local/freeswitch/sounds/flex/app32/teste/Silence.wav flex_digits 2000 ) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 read(1 1 /usr/local/freeswitch/sounds/flex/app32/teste/Silence.wav flex_digits 2000 ) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:17.097927 [DEBUG] switch_ivr_play_say.c:1279 Codec Activated L16@8000hz 1 channels 20ms 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:17.133923 [DEBUG] switch_ivr_play_say.c:1649 done playing file 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:17.373913 [DEBUG] switch_rtp.c:3280 RTP RECV DTMF 1:1120 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:17.375912 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute set(flex_digits) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 set(flex_digits) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:17.375912 [DEBUG] mod_dptools.c:1060 sofia/external/1000123402@192.168.0.154 SET [flex_digits]=[UNDEF] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:17.490911 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute playback(/usr/local/freeswitch/sounds/flex/app32/teste/SelfMuteOn.wav) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154playback(/usr/local/freeswitch/sounds/flex/app32/teste/SelfMuteOn.wav) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:17.490911 [DEBUG] switch_ivr_play_say.c:1279 Codec Activated L16@8000hz 1 channels 20ms 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:19.233824 [DEBUG] switch_ivr_play_say.c:1649 done playing file 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:19.235828 [DEBUG] switch_cpp.cpp:988 sofia/external/1000123402@192.168.0.154destroy/unlink session from object 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:19.235828 [DEBUG] switch_core_codec.c:116 sofia/external/1000123402@192.168.0.154 Push codec L16:70 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:43.433668 [DEBUG] switch_rtp.c:3280 RTP RECV DTMF *:800 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:43.453667 [DEBUG] mod_conference.c:2021 Execute app: socket, localhost:8085 sync full 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:43.453667 [DEBUG] switch_core_codec.c:141 sofia/external/1000123402@192.168.0.154 Restore previous codec PCMU:0. 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 socket(localhost:8085 sync full)
==================================================================================================================================================== While Inside this connection, a "conference 15646 kick [member_id of this channels]" command is executed by a fs_cli console and get stuck while waiting response.
==================================================================================================================================================== 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:44.000850 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute read(1 1 /usr/local/freeswitch/sounds/flex/app32/teste/Silence.wav flex_digits 2000 ) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 read(1 1 /usr/local/freeswitch/sounds/flex/app32/teste/Silence.wav flex_digits 2000 ) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:44.000850 [DEBUG] switch_ivr_play_say.c:1279 Codec Activated L16@8000hz 1 channels 20ms 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:44.033846 [DEBUG] switch_ivr_play_say.c:1649 done playing file 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:44.553821 [DEBUG] switch_rtp.c:3280 RTP RECV DTMF 1:960 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:44.555825 [DEBUG] switch_ivr.c:561 sofia/external/1000123402@192.168.0.154 Command Execute set(flex_digits) 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/ 1000123402@192.168.0.154 set(flex_digits) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:44.555825 [DEBUG] mod_dptools.c:1060 sofia/external/1000123402@192.168.0.154 SET [flex_digits]=[UNDEF] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:56.674244 [DEBUG] switch_channel.c:2560 (sofia/external/1000123402@192.168.0.154) Callstate Change ACTIVE -> HANGUP 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:56.674244 [NOTICE] sofia.c:538 Hangup sofia/external/1000123402@192.168.0.154 [CS_EXECUTE] [NORMAL_CLEARING] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:56.674244 [DEBUG] switch_channel.c:2576 Send signal sofia/external/ 1000123402@192.168.0.154 [KILL] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:56.674244 [DEBUG] switch_core_session.c:1114 Send signal sofia/external/ 1000123402@192.168.0.154 [BREAK] 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:56.675246 [DEBUG] switch_core_session.c:2057 sofia/external/1000123402@192.168.0.154 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:56.675246 [DEBUG] switch_cpp.cpp:988 sofia/external/1000123402@192.168.0.154destroy/unlink session from object 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:56.675246 [DEBUG] switch_core_session.c:2057 sofia/external/1000123402@192.168.0.154 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:56.675246 [DEBUG] switch_core_codec.c:116 sofia/external/1000123402@192.168.0.154 Push codec L16:70 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:56.675246 [DEBUG] mod_conference.c:2815 Channel leaving conference, cause: NORMAL_CLEARING 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:52:56.757239 [DEBUG] mod_conference.c:6104 sofia/external/1000123402@192.168.0.154 skip receive message [UNBRIDGE] (channel is hungup already)
I hope this info helps.
2011/5/12 Michael Collins <msc@freeswitch.org>
On Thu, May 12, 2011 at 12:27 PM, Leonardo P. Bidinoto < leonardo.bidinoto@voicetechnology.com.br> wrote:
Hi Michael,
Im not using to any cdr module.
I would recommend that you do several things:
#1 - update to latest git #2 - rotate logs #3 - enable uuid logging (see logfile.conf.xml - param name "uuid") #4 - reproduce the symptom with a single call (if possible) #5 - pastebin the log for the uuid in question and link to it in this thread
From there hopefully we'll get a clue as to what is happening. -MC
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE: http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Leonardo Pires Bidinoto Voice Technology www.voicetechnology.com.br
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE: http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Leonardo Pires Bidinoto Voice Technology www.voicetechnology.com.br
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Leonardo Pires Bidinoto Voice Technology www.voicetechnology.com.br