[Freeswitch-users] Hanged up callers doubt
Michael Collins
msc at freeswitch.org
Fri May 13 19:08:53 MSD 2011
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
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20110513/6579e15c/attachment-0001.html
More information about the FreeSWITCH-users
mailing list