[Freeswitch-users] Hanged up callers doubt

Leonardo P. Bidinoto leonardo.bidinoto at voicetechnology.com.br
Mon May 16 23:12:24 MSD 2011 

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.154Standard 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.154Standard 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.154 set(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.154 Restore
>> 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.154 destroy/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.154 Restore
>> 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.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 at 192.168.0.154 destroy/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.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 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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20110516/f504dbf2/attachment-0001.html

More information about the FreeSWITCH-users mailing list