[Freeswitch-users] Hanged up callers doubt

Leonardo P. Bidinoto leonardo.bidinoto at voicetechnology.com.br
Fri May 13 18:32:04 MSD 2011


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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20110513/e0feaab7/attachment-0001.html 


More information about the FreeSWITCH-users mailing list