[Freeswitch-users] Hanged up callers doubt

Leonardo P. Bidinoto leonardo.bidinoto at voicetechnology.com.br
Thu Jun 2 23:33:30 MSD 2011


Hi,

About this issue, could be a way to destroy the conference from FS, in a
attempt to remove the stucked channels from the "show channels " and
"conference list"?

2011/5/17 Leonardo P. Bidinoto <leonardo.bidinoto at voicetechnology.com.br>

> 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 at 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 at voicetechnology.com.br> wrote:
>>
>>> hehe, ok michael.
>>>
>>> here is the pastebin link:
>>> http://pastebin.freeswitch.org/16303
>>>
>>>
>>> 2011/5/13 Michael Collins <msc at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.0.154 parsing [public->unloop] continue=false
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/
>>>>> 1000123402 at 192.168.0.154 Regex (PASS) [unloop] ${unroll_loops}(true)
>>>>> =~ /^true$/ break=on-false
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/
>>>>> 1000123402 at 192.168.0.154 Regex (FAIL) [unloop] ${sip_looped_call}() =~
>>>>> /^true$/ break=on-false
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/
>>>>> 1000123402 at 192.168.0.154 parsing [public->public_extensions]
>>>>> continue=false
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/
>>>>> 1000123402 at 192.168.0.154 Regex (PASS) [public_extensions]
>>>>> destination_number(1234567890) =~ /^(\d*)$/ break=on-false
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/
>>>>> 1000123402 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.0.154 Standard EXECUTE
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/
>>>>> 1000123402 at 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 at 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 at 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 at 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 at 192.168.0.154 to XML[1234567890 at default]
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f 2011-05-13 10:51:47.191327 [DEBUG]
>>>>> switch_core_state_machine.c:371 (sofia/external/
>>>>> 1000123402 at 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 at 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 at 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 at 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 at 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 at 192.168.0.154 parsing [default->flex] continue=false
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/
>>>>> 1000123402 at 192.168.0.154 Regex (PASS) [flex]
>>>>> destination_number(1234567890) =~ /^(\d+)$/ break=on-false
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/
>>>>> 1000123402 at 192.168.0.154 Action log(INFO VOICE received
>>>>> dest=1234567890)
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/
>>>>> 1000123402 at 192.168.0.154 Action set(playback_terminators=#)
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/
>>>>> 1000123402 at 192.168.0.154 Action log(INFO Let's do some ivrd, shall
>>>>> we?)
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/
>>>>> 1000123402 at 192.168.0.154 Action
>>>>> set(ivr_path=/usr/local/ipconf/fs/daemon/ivr.rb)
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f Dialplan: sofia/external/
>>>>> 1000123402 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.0.154 Standard EXECUTE
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/
>>>>> 1000123402 at 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 at 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 at 192.168.0.154 SET
>>>>> [playback_terminators]=[#]
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/
>>>>> 1000123402 at 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 at 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 at 192.168.0.154 SET
>>>>> [ivr_path]=[/usr/local/ipconf/fs/daemon/ivr.rb]
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/
>>>>> 1000123402 at 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 at 192.168.0.154 Command
>>>>> Execute answer()
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/
>>>>> 1000123402 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.0.154 Command
>>>>> Execute set(flex_digits)
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/
>>>>> 1000123402 at 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 at 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 at 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 at 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 at 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 at 192.168.0.154 Command
>>>>> Execute set(flex_digits)
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/
>>>>> 1000123402 at 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 at 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 at 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 at 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 at 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 at 192.168.0.154 Command
>>>>> Execute set(flex_digits)
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/
>>>>> 1000123402 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.0.154 Command
>>>>> Execute conference(15646 at teste+flags{waste})
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/
>>>>> 1000123402 at 192.168.0.154 conference(15646 at 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 at 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 at 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 at 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 at 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 at 192.168.0.154Restore previous codec PCMU:0.
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/
>>>>> 1000123402 at 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 at 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 at 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 at 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 at 192.168.0.154 Command
>>>>> Execute set(flex_digits)
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/
>>>>> 1000123402 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.0.154Restore previous codec PCMU:0.
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/
>>>>> 1000123402 at 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 at 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 at 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 at 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 at 192.168.0.154 Command
>>>>> Execute set(flex_digits)
>>>>> 16e09413-9cb0-4011-a635-f91933a35c0f EXECUTE sofia/external/
>>>>> 1000123402 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.0.154skip 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 at 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 at 192.168.0.154skip 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 at 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 at 192.168.0.154 skip
>>>>> receive message [UNBRIDGE] (channel is hungup already)
>>>>>
>>>>> I hope this info helps.
>>>>>
>>>>> 2011/5/12 Michael Collins <msc at freeswitch.org>
>>>>>
>>>>>>
>>>>>>
>>>>>> On Thu, May 12, 2011 at 12:27 PM, Leonardo P. Bidinoto <
>>>>>> leonardo.bidinoto at 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 at 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 at 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 at 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 at 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 at 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
>



-- 
Leonardo Pires Bidinoto
Voice Technology
www.voicetechnology.com.br
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20110602/79aae46b/attachment-0001.html 


More information about the FreeSWITCH-users mailing list