Re: [Freeswitch-users] Qustion about INFO messages after Connect/Answer

19 Oct 2009

      -----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

well, when I add "answer" before I bridge, there is a small change:
There is no INFO message with "unknown" send to callee.

The caller's display isn't affected by "sip_callee_*" chvars.

On 19.10.2009 17:00, Anthony Minessale wrote:
...
you only need to "set" it on the inbound leg and you must answer and
bridge it somewhere.
My current dialplan is this:

    <extension name="Local_Extension">
      <condition field="${ET_is_local}" expression="^true$">
        <action application="set"
data="dialed_extension=${destination_number}"/>
        <action application="answer"/>
        <action application="set" data="sip_callee_id_number=1111"/>
        <action application="set" data="sip_callee_id_name=hubu"/>
        <action application="export" data="sip_callee_id_number=1111"/>
        <action application="export" data="sip_callee_id_name=hubu"/>
        <action application="info"/>
        <action application="export"
data="dialed_extension=${destination_number}"/>
        <action application="set" data="transfer_ringback=$${hold_music}"/>

        <action application="set" data="hangup_after_bridge=true"/>
        <action application="export"
data="nolocal:sip_secure_media=${user_data(${dialed_extension}@${domain_name}
var sip_secure_media)}"/>
        <action application="db"
data="insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}"/>
        <action application="set" data="continue_on_fail=false"/>
        <action application="bridge"
data="user/${dialed_extension}@$${domain}"/>
      </condition>
    </extension>

Here is the complete debug log:

2009-10-19 17:27:20.559060 [DEBUG] sofia.c:4906 IP 85.16.245.206
Approved by acl "clients[]". Access Granted.
2009-10-19 17:27:20.560087 [NOTICE] switch_channel.c:613 New Channel
sofia/internal/1001@85.16.246.12:5061 [e47af3a6-bcc3-11de-9f91-c9cd82739033]
2009-10-19 17:27:20.560087 [DEBUG] sofia.c:3492 Channel
sofia/internal/1001@85.16.246.12:5061 entering state [received][100]
2009-10-19 17:27:20.560087 [DEBUG] sofia.c:3499 Remote SDP:
v=0
o=root 903333206 903333206 IN IP4 85.16.245.206
s=call
c=IN IP4 85.16.245.206
t=0 0
m=audio 54598 RTP/SAVP 0 8 9 99 3 18 4 101
a=rtpmap:0 pcmu/8000
a=rtpmap:8 pcma/8000
a=rtpmap:9 g722/8000
a=rtpmap:99 g726-32/8000
a=rtpmap:3 gsm/8000
a=rtpmap:18 g729/8000
a=rtpmap:4 g723/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=crypto:1 AES_CM_128_HMAC_SHA1_32
inline:zS0VqvwW7z/dnmeWvtZS0AwhJ1ru1J1tuHJO2JRD
a=ptime:20
m=audio 54598 RTP/AVP 0 8 9 99 3 18 4 101
a=rtpmap:0 pcmu/8000
a=rtpmap:8 pcma/8000
a=rtpmap:9 g722/8000
a=rtpmap:99 g726-32/8000
a=rtpmap:3 gsm/8000
a=rtpmap:18 g729/8000
a=rtpmap:4 g723/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20

2009-10-19 17:27:20.560087 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001@85.16.246.12:5061) Running State Change CS_NEW
2009-10-19 17:27:20.560087 [DEBUG] switch_core_state_machine.c:312
(sofia/internal/1001@85.16.246.12:5061) State NEW
2009-10-19 17:27:20.560087 [DEBUG] sofia.c:3620
(sofia/internal/1001@85.16.246.12:5061) State Change CS_NEW -> CS_INIT
2009-10-19 17:27:20.560087 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:20.560087 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001@85.16.246.12:5061) Running State Change CS_INIT
2009-10-19 17:27:20.560087 [DEBUG] switch_core_state_machine.c:330
(sofia/internal/1001@85.16.246.12:5061) State INIT
2009-10-19 17:27:20.560087 [DEBUG] mod_sofia.c:83
sofia/internal/1001@85.16.246.12:5061 SOFIA INIT
2009-10-19 17:27:20.560087 [DEBUG] mod_sofia.c:111
(sofia/internal/1001@85.16.246.12:5061) State Change CS_INIT -> CS_ROUTING
2009-10-19 17:27:20.560087 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:20.560087 [DEBUG] switch_core_state_machine.c:330
(sofia/internal/1001@85.16.246.12:5061) State INIT going to sleep
2009-10-19 17:27:20.560087 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001@85.16.246.12:5061) Running State Change CS_ROUTING
2009-10-19 17:27:20.560087 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/1001@85.16.246.12:5061) State ROUTING
2009-10-19 17:27:20.560087 [DEBUG] mod_sofia.c:130
sofia/internal/1001@85.16.246.12:5061 SOFIA ROUTING
2009-10-19 17:27:20.560087 [DEBUG] switch_core_state_machine.c:78
sofia/internal/1001@85.16.246.12:5061 Standard ROUTING
2009-10-19 17:27:20.560087 [INFO] mod_dialplan_xml.c:391 Processing 1001
an PBX1->1000 in context default
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->anonymous] continue=true
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [anonymous]
destination_number(1000) =~ /^\*31([0-9]+)$/ break=never
Dialplan: sofia/internal/1001@85.16.246.12:5061 ANTI-Action
set(dialed_extension=${destination_number})
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->is_local] continue=true
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [is_local]
${ET_is_local}() =~ /(true|false)/ break=on-true
Dialplan: sofia/internal/1001@85.16.246.12:5061 ANTI-Action
lua(ET_is_local.lua)
Dialplan: sofia/internal/1001@85.16.246.12:5061 ANTI-Action
transfer(${destination_number} XML default)
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->set_domain] continue=true
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (PASS)
[set_domain] destination_number(1000) =~ /^.*$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
set(domain_name=85.16.246.12)
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->302_zero_problem] continue=true
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[302_zero_problem] ${sip_looped_call}() =~ /true/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->fakeTrisko-Servicenumber as callerid] continue=true
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[fakeTrisko-Servicenumber as callerid] caller_id_number(1001) =~
/^(49[1-2][0-9])$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->outbound-ssw-ddi] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[outbound-ssw-ddi] ${dialed_extension}() =~ /^0([0-9]+)$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing [default->mail]
continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [mail]
destination_number(1000) =~ /^9997$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing [default->pizza]
continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [pizza]
destination_number(1000) =~ /^2006$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing [default->pbook]
continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [pbook]
destination_number(1000) =~ /^2007$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->shout_1] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [shout_1]
${dialed_extension}() =~ /^9123$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->shout_2] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [shout_2]
${dialed_extension}() =~ /^9124$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->speex_32000] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[speex_32000] ${dialed_extension}() =~ /^9125$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->speex_32000_2] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[speex_32000_2] ${dialed_extension}() =~ /^9126$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->jukebox] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [jukebox]
destination_number(1000) =~ /^9111$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->pickup-extension] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[pickup-extension] ${dialed_extension}() =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->Voicemail-Verwaltung] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[Voicemail-Verwaltung] ${dialed_extension}() =~ /^(1001|9999)$/
break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->Local_Extension] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[Local_Extension] ${ET_is_local}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->parallel call] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [parallel
call] ${dialed_extension}() =~ /^(6000)$/ break=on-false
2009-10-19 17:27:20.562064 [DEBUG] switch_core_state_machine.c:114
(sofia/internal/1001@85.16.246.12:5061) State Change CS_ROUTING ->
CS_EXECUTE
2009-10-19 17:27:20.562064 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:20.562064 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/1001@85.16.246.12:5061) State ROUTING going to sleep
2009-10-19 17:27:20.563061 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001@85.16.246.12:5061) Running State Change CS_EXECUTE
2009-10-19 17:27:20.563061 [DEBUG] switch_core_state_machine.c:340
(sofia/internal/1001@85.16.246.12:5061) State EXECUTE
2009-10-19 17:27:20.563061 [DEBUG] mod_sofia.c:173
sofia/internal/1001@85.16.246.12:5061 SOFIA EXECUTE
2009-10-19 17:27:20.563061 [DEBUG] switch_core_state_machine.c:151
sofia/internal/1001@85.16.246.12:5061 Standard EXECUTE
EXECUTE sofia/internal/1001@85.16.246.12:5061 set(dialed_extension=1000)
2009-10-19 17:27:20.563061 [DEBUG] mod_dptools.c:752
sofia/internal/1001@85.16.246.12:5061 SET [dialed_extension]=[1000]
EXECUTE sofia/internal/1001@85.16.246.12:5061 lua(ET_is_local.lua)
2009-10-19 17:27:20.588079 [DEBUG] switch_cpp.cpp:925 destroy/unlink
session from object
EXECUTE sofia/internal/1001@85.16.246.12:5061 transfer(1000 XML default)
2009-10-19 17:27:20.588079 [DEBUG] switch_ivr.c:1381
(sofia/internal/1001@85.16.246.12:5061) State Change CS_EXECUTE ->
CS_ROUTING
2009-10-19 17:27:20.588079 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:20.588079 [DEBUG] switch_ivr.c:1385
sofia/internal/1001@85.16.246.12:5061 receive message [TRANSFER]
2009-10-19 17:27:20.588079 [DEBUG] switch_core_session.c:639 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:20.588079 [NOTICE] switch_ivr.c:1387 Transfer
sofia/internal/1001@85.16.246.12:5061 to XML[1000@default]
2009-10-19 17:27:20.588079 [DEBUG] switch_core_state_machine.c:340
(sofia/internal/1001@85.16.246.12:5061) State EXECUTE going to sleep
2009-10-19 17:27:20.588079 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001@85.16.246.12:5061) Running State Change CS_ROUTING
2009-10-19 17:27:20.588079 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/1001@85.16.246.12:5061) State ROUTING
2009-10-19 17:27:20.588079 [DEBUG] mod_sofia.c:130
sofia/internal/1001@85.16.246.12:5061 SOFIA ROUTING
2009-10-19 17:27:20.588079 [DEBUG] switch_core_state_machine.c:78
sofia/internal/1001@85.16.246.12:5061 Standard ROUTING
2009-10-19 17:27:20.588079 [INFO] mod_dialplan_xml.c:391 Processing 1001
an PBX1->1000 in context default
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->anonymous] continue=true
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [anonymous]
destination_number(1000) =~ /^\*31([0-9]+)$/ break=never
Dialplan: sofia/internal/1001@85.16.246.12:5061 ANTI-Action
set(dialed_extension=${destination_number})
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->is_local] continue=true
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (PASS) [is_local]
${ET_is_local}(true) =~ /(true|false)/ break=on-true
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->set_domain] continue=true
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (PASS)
[set_domain] destination_number(1000) =~ /^.*$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
set(domain_name=85.16.246.12)
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->302_zero_problem] continue=true
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[302_zero_problem] ${sip_looped_call}() =~ /true/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->fakeTrisko-Servicenumber as callerid] continue=true
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[fakeTrisko-Servicenumber as callerid] caller_id_number(1001) =~
/^(49[1-2][0-9])$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->outbound-ssw-ddi] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[outbound-ssw-ddi] ${dialed_extension}(1000) =~ /^0([0-9]+)$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing [default->mail]
continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [mail]
destination_number(1000) =~ /^9997$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing [default->pizza]
continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [pizza]
destination_number(1000) =~ /^2006$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing [default->pbook]
continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [pbook]
destination_number(1000) =~ /^2007$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->shout_1] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [shout_1]
${dialed_extension}(1000) =~ /^9123$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->shout_2] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [shout_2]
${dialed_extension}(1000) =~ /^9124$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->speex_32000] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[speex_32000] ${dialed_extension}(1000) =~ /^9125$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->speex_32000_2] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[speex_32000_2] ${dialed_extension}(1000) =~ /^9126$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->jukebox] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL) [jukebox]
destination_number(1000) =~ /^9111$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->pickup-extension] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[pickup-extension] ${dialed_extension}(1000) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->Voicemail-Verwaltung] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (FAIL)
[Voicemail-Verwaltung] ${dialed_extension}(1000) =~ /^(1001|9999)$/
break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 parsing
[default->Local_Extension] continue=false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Regex (PASS)
[Local_Extension] ${ET_is_local}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
set(dialed_extension=${destination_number})
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action answer()
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
set(sip_callee_id_number=1111)
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
set(sip_callee_id_name=hubu)
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
export(sip_callee_id_number=1111)
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
export(sip_callee_id_name=hubu)
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action info()
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
export(dialed_extension=${destination_number})
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
set(hangup_after_bridge=true)
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
export(nolocal:sip_secure_media=${user_data(${dialed_extension}@${domain_name}
var sip_secure_media)})
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
db(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
set(continue_on_fail=false)
Dialplan: sofia/internal/1001@85.16.246.12:5061 Action
bridge(user/${dialed_extension}@85.16.246.12)
2009-10-19 17:27:20.590066 [DEBUG] switch_core_state_machine.c:114
(sofia/internal/1001@85.16.246.12:5061) State Change CS_ROUTING ->
CS_EXECUTE
2009-10-19 17:27:20.590066 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:20.590066 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/1001@85.16.246.12:5061) State ROUTING going to sleep
2009-10-19 17:27:20.590066 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001@85.16.246.12:5061) Running State Change CS_EXECUTE
2009-10-19 17:27:20.590066 [DEBUG] switch_core_state_machine.c:340
(sofia/internal/1001@85.16.246.12:5061) State EXECUTE
2009-10-19 17:27:20.590066 [DEBUG] mod_sofia.c:173
sofia/internal/1001@85.16.246.12:5061 SOFIA EXECUTE
2009-10-19 17:27:20.591072 [DEBUG] switch_core_state_machine.c:151
sofia/internal/1001@85.16.246.12:5061 Standard EXECUTE
EXECUTE sofia/internal/1001@85.16.246.12:5061 set(dialed_extension=1000)
2009-10-19 17:27:20.591072 [DEBUG] mod_dptools.c:752
sofia/internal/1001@85.16.246.12:5061 SET [dialed_extension]=[1000]
EXECUTE sofia/internal/1001@85.16.246.12:5061 set(domain_name=85.16.246.12)
2009-10-19 17:27:20.591072 [DEBUG] mod_dptools.c:752
sofia/internal/1001@85.16.246.12:5061 SET [domain_name]=[85.16.246.12]
EXECUTE sofia/internal/1001@85.16.246.12:5061 set(dialed_extension=1000)
2009-10-19 17:27:20.591072 [DEBUG] mod_dptools.c:752
sofia/internal/1001@85.16.246.12:5061 SET [dialed_extension]=[1000]
EXECUTE sofia/internal/1001@85.16.246.12:5061 answer()
2009-10-19 17:27:20.591072 [DEBUG] mod_dptools.c:653
sofia/internal/1001@85.16.246.12:5061 receive message [ANSWER]
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:3028 Set Remote Key [1
AES_CM_128_HMAC_SHA1_32 inline:zS0VqvwW7z/dnmeWvtZS0AwhJ1ru1J1tuHJO2JRD]
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:2160 Set Local Key [1
AES_CM_128_HMAC_SHA1_32 inline:GteACgi6L6LMWBxdEnW4/XSOUhsmp/iKk9dZjmBJ]
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:3142 Audio Codec Compare
[pcmu:0:8000:20]/[CELT:95:48000:10]
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:3142 Audio Codec Compare
[pcmu:0:8000:20]/[SPEEX:103:32000:20]
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:3142 Audio Codec Compare
[pcmu:0:8000:20]/[G722:9:8000:20]
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:3142 Audio Codec Compare
[pcmu:0:8000:20]/[PCMA:8:8000:20]
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:3142 Audio Codec Compare
[pcma:8:8000:20]/[CELT:95:48000:10]
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:3142 Audio Codec Compare
[pcma:8:8000:20]/[SPEEX:103:32000:20]
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:3142 Audio Codec Compare
[pcma:8:8000:20]/[G722:9:8000:20]
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:3142 Audio Codec Compare
[pcma:8:8000:20]/[PCMA:8:8000:20]
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:2100 Set Codec
sofia/internal/1001@85.16.246.12:5061 PCMA/8000 20 ms 160 samples
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:3102 Set 2833 dtmf
payload to 101
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:3076 Our existing sdp is
still good [pcma 85.16.245.206:54598], let's keep it.
2009-10-19 17:27:20.591072 [DEBUG] sofia_glue.c:2334 AUDIO RTP
[sofia/internal/1001@85.16.246.12:5061] 85.16.246.12 port 14580 ->
85.16.245.206 port 54598 codec: 8 ms: 20
2009-10-19 17:27:20.591072 [DEBUG] switch_rtp.c:1155 Starting timer
[soft] 160 bytes per 20ms
2009-10-19 17:27:20.594059 [INFO] switch_rtp.c:1019 Activating Secure
RTP SEND
2009-10-19 17:27:20.594059 [INFO] switch_rtp.c:999 Activating Secure RTP
RECV
2009-10-19 17:27:20.594059 [DEBUG] switch_core_sqldb.c:396 Secure Type:
srtp:AES_CM_128_HMAC_SHA1_32
2009-10-19 17:27:20.594059 [DEBUG] switch_core_sqldb.c:396 Secure Type:
srtp:AES_CM_128_HMAC_SHA1_32
2009-10-19 17:27:20.594059 [NOTICE] sofia_glue.c:2769 Pre-Answer
sofia/internal/1001@85.16.246.12:5061!
2009-10-19 17:27:20.594059 [DEBUG] mod_sofia.c:543 Local SDP
sofia/internal/1001@85.16.246.12:5061:
v=0
o=FreeSWITCH 1255951460 1255951461 IN IP4 85.16.246.12
s=FreeSWITCH
c=IN IP4 85.16.246.12
t=0 0
m=audio 14580 RTP/SAVP 8 101
a=rtpmap:8 pcma/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
a=crypto:1 AES_CM_128_HMAC_SHA1_32
inline:GteACgi6L6LMWBxdEnW4/XSOUhsmp/iKk9dZjmBJ

2009-10-19 17:27:20.594059 [DEBUG] switch_core_session.c:639 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:20.594059 [NOTICE] mod_dptools.c:653 Channel
[sofia/internal/1001@85.16.246.12:5061] has been answered
2009-10-19 17:27:20.594059 [DEBUG] switch_channel.c:182
sofia/internal/1001@85.16.246.12:5061 receive message [AUDIO_SYNC]
EXECUTE sofia/internal/1001@85.16.246.12:5061 set(sip_callee_id_number=1111)
2009-10-19 17:27:20.594059 [DEBUG] mod_dptools.c:752
sofia/internal/1001@85.16.246.12:5061 SET [sip_callee_id_number]=[1111]
2009-10-19 17:27:20.595060 [DEBUG] sofia.c:3492 Channel
sofia/internal/1001@85.16.246.12:5061 entering state [completed][200]
EXECUTE sofia/internal/1001@85.16.246.12:5061 set(sip_callee_id_name=hubu)
2009-10-19 17:27:20.595060 [DEBUG] mod_dptools.c:752
sofia/internal/1001@85.16.246.12:5061 SET [sip_callee_id_name]=[hubu]
EXECUTE sofia/internal/1001@85.16.246.12:5061
export(sip_callee_id_number=1111)
2009-10-19 17:27:20.595060 [DEBUG] mod_dptools.c:896 EXPORT
[sip_callee_id_number]=[1111]
EXECUTE sofia/internal/1001@85.16.246.12:5061
export(sip_callee_id_name=hubu)
2009-10-19 17:27:20.595060 [DEBUG] mod_dptools.c:896 EXPORT
[sip_callee_id_name]=[hubu]
EXECUTE sofia/internal/1001@85.16.246.12:5061 info()
2009-10-19 17:27:20.596059 [INFO] mod_dptools.c:961 CHANNEL_DATA:
Channel-State: [CS_EXECUTE]
Channel-State-Number: [4]
Channel-Name: [sofia/internal/1001@85.16.246.12:5061]
Unique-ID: [e47af3a6-bcc3-11de-9f91-c9cd82739033]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Answer-State: [answered]
Channel-Read-Codec-Name: [PCMA]
Channel-Read-Codec-Rate: [8000]
Channel-Write-Codec-Name: [PCMA]
Channel-Write-Codec-Rate: [8000]
Caller-Username: [1001]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [1001 an PBX1]
Caller-Caller-ID-Number: [1001]
Caller-Network-Addr: [85.16.245.206]
Caller-Destination-Number: [1000]
Caller-Unique-ID: [e47af3a6-bcc3-11de-9f91-c9cd82739033]
Caller-Source: [mod_sofia]
Caller-Context: [default]
Caller-RDNIS: [1000]
Caller-Channel-Name: [sofia/internal/1001@85.16.246.12:5061]
Caller-Profile-Index: [2]
Caller-Profile-Created-Time: [1255966040588079]
Caller-Channel-Created-Time: [1255966040560087]
Caller-Channel-Answered-Time: [1255966040594059]
Caller-Channel-Progress-Time: [0]
Caller-Channel-Progress-Media-Time: [1255966040594059]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
variable_sip_received_ip: [85.16.245.206]
variable_sip_received_port: [1024]
variable_sip_via_protocol: [udp]
variable_sip_authorized: [true]
variable_sip_from_user: [1001]
variable_sip_from_port: [5061]
variable_sip_from_uri: [1001@85.16.246.12:5061]
variable_sip_from_host: [85.16.246.12]
variable_sip_from_user_stripped: [1001]
variable_sip_from_tag: [02p9o5jbg8]
variable_sofia_profile_name: [internal]
variable_sip_req_params: [user=phone]
variable_sip_req_user: [1000]
variable_sip_req_port: [5061]
variable_sip_req_uri: [1000@85.16.246.12:5061]
variable_sip_req_host: [85.16.246.12]
variable_sip_to_params: [user=phone]
variable_sip_to_user: [1000]
variable_sip_to_port: [5061]
variable_sip_to_uri: [1000@85.16.246.12:5061]
variable_sip_to_host: [85.16.246.12]
variable_sip_contact_params: [line=eg3wp69a]
variable_sip_contact_user: [1001]
variable_sip_contact_port: [1024]
variable_sip_contact_uri: [1001@85.16.245.206:1024]
variable_sip_contact_host: [85.16.245.206]
variable_channel_name: [sofia/internal/1001@85.16.246.12:5061]
variable_sip_call_id: [3c2d38a1cd82-iphmvbhl46hj]
variable_sip_user_agent: [snom820/8.2.16]
variable_sip_via_host: [85.16.245.206]
variable_sip_via_port: [1024]
variable_sip_via_rport: [1024]
variable_presence_id: [1001@85.16.246.12]
variable_sip_h_X-Serialnumber: [0004134002CB]
variable_sip_h_P-Key-Flags: [resolution="31x13", keys="4"]
variable_switch_r_sdp: [v=0
o=root 903333206 903333206 IN IP4 85.16.245.206
s=call
c=IN IP4 85.16.245.206
t=0 0
m=audio 54598 RTP/SAVP 0 8 9 99 3 18 4 101
a=rtpmap:0 pcmu/8000
a=rtpmap:8 pcma/8000
a=rtpmap:9 g722/8000
a=rtpmap:99 g726-32/8000
a=rtpmap:3 gsm/8000
a=rtpmap:18 g729/8000
a=rtpmap:4 g723/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=crypto:1 AES_CM_128_HMAC_SHA1_32
inline:zS0VqvwW7z/dnmeWvtZS0AwhJ1ru1J1tuHJO2JRD
a=ptime:20
m=audio 54598 RTP/AVP 0 8 9 99 3 18 4 101
a=rtpmap:0 pcmu/8000
a=rtpmap:8 pcma/8000
a=rtpmap:9 g722/8000
a=rtpmap:99 g726-32/8000
a=rtpmap:3 gsm/8000
a=rtpmap:18 g729/8000
a=rtpmap:4 g723/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
]
variable_ep_codec_string: [G722@8000h@20i,PCMA@8000h@20i]
variable_ET_is_local: [true]
variable_max_forwards: [69]
variable_domain_name: [85.16.246.12]
variable_dialed_extension: [1000]
variable_sip_has_crypto: [AES_CM_128_HMAC_SHA1_32]
variable_sip_crypto_mandatory: [true]
variable_sip_secure_media: [true]
variable_remote_media_ip: [85.16.245.206]
variable_remote_media_port: [54598]
variable_read_codec: [PCMA]
variable_read_rate: [8000]
variable_write_codec: [PCMA]
variable_write_rate: [8000]
variable_local_media_ip: [85.16.246.12]
variable_local_media_port: [14580]
variable_sip_secure_media_confirmed: [true]
variable_endpoint_disposition: [ANSWER]
variable_sip_callee_id_number: [1111]
variable_sip_callee_id_name: [hubu]
variable_export_vars: [sip_callee_id_number,sip_callee_id_name]
variable_current_application: [info]

EXECUTE sofia/internal/1001@85.16.246.12:5061 export(dialed_extension=1000)
2009-10-19 17:27:20.596059 [DEBUG] mod_dptools.c:896 EXPORT
[dialed_extension]=[1000]
EXECUTE sofia/internal/1001@85.16.246.12:5061
set(transfer_ringback=local_stream://moh)
2009-10-19 17:27:20.596059 [DEBUG] mod_dptools.c:752
sofia/internal/1001@85.16.246.12:5061 SET
[transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/1001@85.16.246.12:5061 set(hangup_after_bridge=true)
2009-10-19 17:27:20.597073 [DEBUG] mod_dptools.c:752
sofia/internal/1001@85.16.246.12:5061 SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/1001@85.16.246.12:5061
export(nolocal:sip_secure_media=)
2009-10-19 17:27:20.621072 [DEBUG] mod_dptools.c:896 EXPORT (REMOTE
ONLY) [sip_secure_media]=[UNDEF]
EXECUTE sofia/internal/1001@85.16.246.12:5061
db(insert/85.16.246.12-last_dial//e47af3a6-bcc3-11de-9f91-c9cd82739033)
2009-10-19 17:27:20.832283 [DEBUG] sofia.c:3492 Channel
sofia/internal/1001@85.16.246.12:5061 entering state [ready][200]
EXECUTE sofia/internal/1001@85.16.246.12:5061 set(continue_on_fail=false)
2009-10-19 17:27:20.841267 [DEBUG] mod_dptools.c:752
sofia/internal/1001@85.16.246.12:5061 SET [continue_on_fail]=[false]
EXECUTE sofia/internal/1001@85.16.246.12:5061 bridge(user/1000@85.16.246.12)
2009-10-19 17:27:20.865064 [DEBUG] switch_ivr_originate.c:1162 variable
string 0 = [presence_id=1000@85.16.246.12]
2009-10-19 17:27:20.865064 [NOTICE] switch_channel.c:613 New Channel
sofia/internal/sip:1000@85.16.245.228:1024
[e4a9a7a0-bcc3-11de-9f91-c9cd82739033]
2009-10-19 17:27:20.866297 [DEBUG] mod_sofia.c:2981
(sofia/internal/sip:1000@85.16.245.228:1024) State Change CS_NEW -> CS_INIT
2009-10-19 17:27:20.866297 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/sip:1000@85.16.245.228:1024 [BREAK]
2009-10-19 17:27:20.866297 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/sip:1000@85.16.245.228:1024) Running State Change CS_INIT
2009-10-19 17:27:20.866297 [DEBUG] switch_core_state_machine.c:330
(sofia/internal/sip:1000@85.16.245.228:1024) State INIT
2009-10-19 17:27:20.866297 [DEBUG] mod_sofia.c:83
sofia/internal/sip:1000@85.16.245.228:1024 SOFIA INIT
2009-10-19 17:27:20.866297 [DEBUG] mod_sofia.c:111
(sofia/internal/sip:1000@85.16.245.228:1024) State Change CS_INIT ->
CS_ROUTING
2009-10-19 17:27:20.866297 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/sip:1000@85.16.245.228:1024 [BREAK]
2009-10-19 17:27:20.866297 [DEBUG] switch_core_state_machine.c:330
(sofia/internal/sip:1000@85.16.245.228:1024) State INIT going to sleep
2009-10-19 17:27:20.866297 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/sip:1000@85.16.245.228:1024) Running State Change CS_ROUTING
2009-10-19 17:27:20.866297 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/sip:1000@85.16.245.228:1024) State ROUTING
2009-10-19 17:27:20.866297 [DEBUG] mod_sofia.c:130
sofia/internal/sip:1000@85.16.245.228:1024 SOFIA ROUTING
2009-10-19 17:27:20.866297 [DEBUG] switch_ivr_originate.c:66
(sofia/internal/sip:1000@85.16.245.228:1024) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2009-10-19 17:27:20.866297 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/sip:1000@85.16.245.228:1024 [BREAK]
2009-10-19 17:27:20.866297 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/sip:1000@85.16.245.228:1024) State ROUTING going to sleep
2009-10-19 17:27:20.866297 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/sip:1000@85.16.245.228:1024) Running State Change
CS_CONSUME_MEDIA
2009-10-19 17:27:20.866297 [DEBUG] switch_ivr_originate.c:1880 Raw Codec
Activation Success L16@8000hz 1 channel 20ms
2009-10-19 17:27:20.866297 [DEBUG] switch_ivr_originate.c:1912 Play
Ringback File [local_stream://moh]
2009-10-19 17:27:20.866297 [DEBUG] mod_local_stream.c:408 Opening Stream
[moh/8000] 8000hz
2009-10-19 17:27:20.866297 [DEBUG] switch_core_state_machine.c:352
(sofia/internal/sip:1000@85.16.245.228:1024) State CONSUME_MEDIA
2009-10-19 17:27:20.866297 [DEBUG] switch_core_state_machine.c:352
(sofia/internal/sip:1000@85.16.245.228:1024) State CONSUME_MEDIA going
to sleep
2009-10-19 17:27:20.868064 [DEBUG] sofia.c:3492 Channel
sofia/internal/sip:1000@85.16.245.228:1024 entering state [calling][0]
2009-10-19 17:27:20.877064 [DEBUG] switch_core_io.c:652
sofia/internal/1001@85.16.246.12:5061 receive message
[TRANSCODING_NECESSARY]
2009-10-19 17:27:20.887288 [DEBUG] sofia.c:3492 Channel
sofia/internal/sip:1000@85.16.245.228:1024 entering state [proceeding][180]
2009-10-19 17:27:20.887288 [NOTICE] sofia.c:3556 Ring-Ready
sofia/internal/sip:1000@85.16.245.228:1024!
2009-10-19 17:27:21.392073 [DEBUG] sofia.c:3492 Channel
sofia/internal/sip:1000@85.16.245.228:1024 entering state [proceeding][180]
2009-10-19 17:27:22.403086 [DEBUG] sofia.c:3492 Channel
sofia/internal/sip:1000@85.16.245.228:1024 entering state [proceeding][180]
2009-10-19 17:27:22.849092 [DEBUG] sofia.c:3492 Channel
sofia/internal/sip:1000@85.16.245.228:1024 entering state [ready][200]
2009-10-19 17:27:22.849092 [DEBUG] sofia.c:3499 Remote SDP:
v=0
o=root 1600007648 1600007649 IN IP4 85.16.245.228
s=call
c=IN IP4 85.16.245.228
t=0 0
m=audio 50468 RTP/AVP 8 9 101
a=rtpmap:8 pcma/8000
a=rtpmap:9 g722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20

2009-10-19 17:27:22.849092 [DEBUG] sofia_glue.c:3142 Audio Codec Compare
[pcma:8:8000:20]/[PCMA:8:8000:20]
2009-10-19 17:27:22.849092 [DEBUG] sofia_glue.c:2100 Set Codec
sofia/internal/sip:1000@85.16.245.228:1024 PCMA/8000 20 ms 160 samples
2009-10-19 17:27:22.849092 [DEBUG] sofia_glue.c:3102 Set 2833 dtmf
payload to 101
2009-10-19 17:27:22.849092 [DEBUG] sofia_glue.c:2334 AUDIO RTP
[sofia/internal/sip:1000@85.16.245.228:1024] 85.16.246.12 port 16276 ->
85.16.245.228 port 50468 codec: 8 ms: 20
2009-10-19 17:27:22.850096 [DEBUG] switch_rtp.c:1155 Starting timer
[soft] 160 bytes per 20ms
2009-10-19 17:27:22.851093 [DEBUG] switch_channel.c:2046 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:22.851093 [NOTICE] sofia.c:3982 Channel
[sofia/internal/sip:1000@85.16.245.228:1024] has been answered
2009-10-19 17:27:22.851093 [DEBUG] switch_channel.c:182
sofia/internal/sip:1000@85.16.245.228:1024 receive message [AUDIO_SYNC]
2009-10-19 17:27:22.857294 [DEBUG] switch_core_codec.c:122 Restore
original codec.
2009-10-19 17:27:22.857294 [DEBUG] switch_ivr_originate.c:2363 Originate
Resulted in Success: [sofia/internal/sip:1000@85.16.245.228:1024]
2009-10-19 17:27:22.857294 [DEBUG] switch_channel.c:182
sofia/internal/sip:1000@85.16.245.228:1024 receive message [AUDIO_SYNC]
2009-10-19 17:27:22.857294 [DEBUG] switch_channel.c:182
sofia/internal/1001@85.16.246.12:5061 receive message [AUDIO_SYNC]
2009-10-19 17:27:22.857294 [DEBUG] switch_ivr_originate.c:1880 Raw Codec
Activation Success L16@8000hz 1 channel 20ms
2009-10-19 17:27:22.858097 [DEBUG] switch_ivr_originate.c:1912 Play
Ringback File [local_stream://moh]
2009-10-19 17:27:22.858097 [DEBUG] mod_local_stream.c:408 Opening Stream
[moh/8000] 8000hz
2009-10-19 17:27:22.858097 [DEBUG] switch_core_codec.c:122 Restore
original codec.
2009-10-19 17:27:22.858097 [DEBUG] switch_ivr_originate.c:2363 Originate
Resulted in Success: [sofia/internal/sip:1000@85.16.245.228:1024]
2009-10-19 17:27:22.858097 [DEBUG] switch_channel.c:182
sofia/internal/sip:1000@85.16.245.228:1024 receive message [AUDIO_SYNC]
2009-10-19 17:27:22.858097 [DEBUG] switch_channel.c:182
sofia/internal/1001@85.16.246.12:5061 receive message [AUDIO_SYNC]
2009-10-19 17:27:22.858097 [DEBUG] switch_ivr_bridge.c:966
sofia/internal/sip:1000@85.16.245.228:1024 receive message [BRIDGE]
2009-10-19 17:27:22.858097 [DEBUG] switch_core_session.c:639 Send signal
sofia/internal/sip:1000@85.16.245.228:1024 [BREAK]
2009-10-19 17:27:22.858097 [DEBUG] switch_ivr_bridge.c:973
sofia/internal/1001@85.16.246.12:5061 receive message [BRIDGE]
2009-10-19 17:27:22.858097 [DEBUG] switch_core_session.c:639 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:22.858097 [DEBUG] switch_ivr_bridge.c:1017
(sofia/internal/sip:1000@85.16.245.228:1024) State Change
CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2009-10-19 17:27:22.858097 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/sip:1000@85.16.245.228:1024 [BREAK]
2009-10-19 17:27:22.858097 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/sip:1000@85.16.245.228:1024) Running State Change
CS_EXCHANGE_MEDIA
2009-10-19 17:27:22.858097 [DEBUG] switch_core_state_machine.c:343
(sofia/internal/sip:1000@85.16.245.228:1024) State EXCHANGE_MEDIA
2009-10-19 17:27:22.858097 [DEBUG] mod_sofia.c:436 SOFIA LOOPBACK
2009-10-19 17:27:22.877303 [DEBUG] switch_ivr_bridge.c:115
sofia/internal/sip:1000@85.16.245.228:1024 receive message [DISPLAY]
2009-10-19 17:27:22.877303 [DEBUG] switch_ivr_bridge.c:115
sofia/internal/1001@85.16.246.12:5061 receive message [DISPLAY]
2009-10-19 17:27:24.568124 [NOTICE] sofia.c:328 Hangup
sofia/internal/sip:1000@85.16.245.228:1024 [CS_EXCHANGE_MEDIA]
[NORMAL_CLEARING]
2009-10-19 17:27:24.568124 [DEBUG] switch_channel.c:1837 Send signal
sofia/internal/sip:1000@85.16.245.228:1024 [KILL]
2009-10-19 17:27:24.568124 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/sip:1000@85.16.245.228:1024 [BREAK]
2009-10-19 17:27:24.568124 [DEBUG] switch_core_state_machine.c:449
thread mismatch skipping state handler.
2009-10-19 17:27:24.577124 [DEBUG] switch_ivr_bridge.c:446
sofia/internal/sip:1000@85.16.245.228:1024 ending bridge by request from
read function
2009-10-19 17:27:24.577124 [DEBUG] switch_ivr_bridge.c:521 BRIDGE THREAD
DONE [sofia/internal/sip:1000@85.16.245.228:1024]
2009-10-19 17:27:24.577124 [DEBUG] switch_ivr_bridge.c:523 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:24.577124 [DEBUG] switch_core_state_machine.c:343
(sofia/internal/sip:1000@85.16.245.228:1024) State EXCHANGE_MEDIA going
to sleep
2009-10-19 17:27:24.577124 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/sip:1000@85.16.245.228:1024) Running State Change CS_HANGUP
2009-10-19 17:27:24.577124 [DEBUG] switch_ivr_bridge.c:440
sofia/internal/sip:1000@85.16.245.228:1024 ending bridge by request from
write function
2009-10-19 17:27:24.577124 [DEBUG] switch_ivr_bridge.c:495
sofia/internal/1001@85.16.246.12:5061 receive message [UNBRIDGE]
2009-10-19 17:27:24.577124 [DEBUG] switch_core_session.c:639 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:24.577124 [DEBUG] switch_ivr_bridge.c:521 BRIDGE THREAD
DONE [sofia/internal/1001@85.16.246.12:5061]
2009-10-19 17:27:24.577124 [DEBUG] switch_ivr_bridge.c:523 Send signal
sofia/internal/sip:1000@85.16.245.228:1024 [BREAK]
2009-10-19 17:27:24.577124 [NOTICE] switch_ivr_bridge.c:1093 Hangup
sofia/internal/1001@85.16.246.12:5061 [CS_EXECUTE] [NORMAL_CLEARING]
2009-10-19 17:27:24.577124 [DEBUG] switch_channel.c:1837 Send signal
sofia/internal/1001@85.16.246.12:5061 [KILL]
2009-10-19 17:27:24.577124 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:24.577124 [DEBUG] switch_core_state_machine.c:476
(sofia/internal/sip:1000@85.16.245.228:1024) State HANGUP
2009-10-19 17:27:24.577124 [DEBUG] mod_sofia.c:344 Channel
sofia/internal/sip:1000@85.16.245.228:1024 hanging up, cause:
NORMAL_CLEARING
2009-10-19 17:27:24.577124 [DEBUG] switch_core_state_machine.c:46
sofia/internal/sip:1000@85.16.245.228:1024 Standard HANGUP, cause:
NORMAL_CLEARING
2009-10-19 17:27:24.577124 [DEBUG] switch_core_state_machine.c:476
(sofia/internal/sip:1000@85.16.245.228:1024) State HANGUP going to sleep
2009-10-19 17:27:24.578354 [DEBUG] switch_core_state_machine.c:325
(sofia/internal/sip:1000@85.16.245.228:1024) State Change CS_HANGUP ->
CS_REPORTING
2009-10-19 17:27:24.578354 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/sip:1000@85.16.245.228:1024 [BREAK]
2009-10-19 17:27:24.578354 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/sip:1000@85.16.245.228:1024) Running State Change
CS_REPORTING
2009-10-19 17:27:24.578354 [DEBUG] switch_core_state_machine.c:567
(sofia/internal/sip:1000@85.16.245.228:1024) State REPORTING
2009-10-19 17:27:24.578354 [DEBUG] switch_core_state_machine.c:53
sofia/internal/sip:1000@85.16.245.228:1024 Standard REPORTING, cause:
NORMAL_CLEARING
2009-10-19 17:27:24.578354 [DEBUG] switch_core_state_machine.c:567
(sofia/internal/sip:1000@85.16.245.228:1024) State REPORTING going to sleep
2009-10-19 17:27:24.578354 [DEBUG] switch_core_state_machine.c:319
(sofia/internal/sip:1000@85.16.245.228:1024) State Change CS_REPORTING
- -> CS_DESTROY
2009-10-19 17:27:24.578354 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/sip:1000@85.16.245.228:1024 [BREAK]
2009-10-19 17:27:24.578354 [DEBUG] switch_core_state_machine.c:476
(sofia/internal/1001@85.16.246.12:5061) State HANGUP
2009-10-19 17:27:24.578354 [DEBUG] mod_sofia.c:344 Channel
sofia/internal/1001@85.16.246.12:5061 hanging up, cause: NORMAL_CLEARING
2009-10-19 17:27:24.578354 [DEBUG] switch_core_session.c:1106 Session 46
(sofia/internal/sip:1000@85.16.245.228:1024) Locked, Waiting on external
entities
2009-10-19 17:27:24.578354 [DEBUG] mod_sofia.c:382 Sending BYE to
sofia/internal/1001@85.16.246.12:5061
2009-10-19 17:27:24.579127 [DEBUG] switch_core_state_machine.c:46
sofia/internal/1001@85.16.246.12:5061 Standard HANGUP, cause:
NORMAL_CLEARING
2009-10-19 17:27:24.579127 [DEBUG] switch_core_state_machine.c:476
(sofia/internal/1001@85.16.246.12:5061) State HANGUP going to sleep
2009-10-19 17:27:24.579127 [NOTICE] switch_core_session.c:1124 Session
46 (sofia/internal/sip:1000@85.16.245.228:1024) Ended
2009-10-19 17:27:24.579127 [NOTICE] switch_core_session.c:1126 Close
Channel sofia/internal/sip:1000@85.16.245.228:1024 [CS_DESTROY]
2009-10-19 17:27:24.579127 [DEBUG] switch_core_state_machine.c:413
(sofia/internal/sip:1000@85.16.245.228:1024) Running State Change CS_DESTROY
2009-10-19 17:27:24.579127 [DEBUG] switch_core_state_machine.c:340
(sofia/internal/1001@85.16.246.12:5061) State EXECUTE going to sleep
2009-10-19 17:27:24.579127 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001@85.16.246.12:5061) Running State Change CS_HANGUP
2009-10-19 17:27:24.579127 [DEBUG] switch_core_state_machine.c:424
(sofia/internal/sip:1000@85.16.245.228:1024) State DESTROY
2009-10-19 17:27:24.579127 [DEBUG] mod_sofia.c:261
sofia/internal/sip:1000@85.16.245.228:1024 SOFIA DESTROY
2009-10-19 17:27:24.579127 [DEBUG] switch_core_state_machine.c:60
sofia/internal/sip:1000@85.16.245.228:1024 Standard DESTROY
2009-10-19 17:27:24.579127 [DEBUG] switch_core_state_machine.c:454
handler already called, skipping state handler.
2009-10-19 17:27:24.579127 [DEBUG] switch_core_state_machine.c:424
(sofia/internal/sip:1000@85.16.245.228:1024) State DESTROY going to sleep
2009-10-19 17:27:24.579127 [DEBUG] switch_core_state_machine.c:325
(sofia/internal/1001@85.16.246.12:5061) State Change CS_HANGUP ->
CS_REPORTING
2009-10-19 17:27:24.579127 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:24.579127 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001@85.16.246.12:5061) Running State Change CS_REPORTING
2009-10-19 17:27:24.579127 [DEBUG] switch_core_state_machine.c:567
(sofia/internal/1001@85.16.246.12:5061) State REPORTING
2009-10-19 17:27:24.581127 [DEBUG] switch_core_state_machine.c:53
sofia/internal/1001@85.16.246.12:5061 Standard REPORTING, cause:
NORMAL_CLEARING
2009-10-19 17:27:24.581127 [DEBUG] switch_core_state_machine.c:567
(sofia/internal/1001@85.16.246.12:5061) State REPORTING going to sleep
2009-10-19 17:27:24.581127 [DEBUG] switch_core_state_machine.c:319
(sofia/internal/1001@85.16.246.12:5061) State Change CS_REPORTING ->
CS_DESTROY
2009-10-19 17:27:24.581127 [DEBUG] switch_core_session.c:969 Send signal
sofia/internal/1001@85.16.246.12:5061 [BREAK]
2009-10-19 17:27:24.581127 [DEBUG] switch_core_session.c:1106 Session 45
(sofia/internal/1001@85.16.246.12:5061) Locked, Waiting on external entities
2009-10-19 17:27:24.581127 [NOTICE] switch_core_session.c:1124 Session
45 (sofia/internal/1001@85.16.246.12:5061) Ended
2009-10-19 17:27:24.581127 [NOTICE] switch_core_session.c:1126 Close
Channel sofia/internal/1001@85.16.246.12:5061 [CS_DESTROY]
2009-10-19 17:27:24.581127 [DEBUG] switch_core_state_machine.c:413
(sofia/internal/1001@85.16.246.12:5061) Running State Change CS_DESTROY
2009-10-19 17:27:24.581127 [DEBUG] switch_core_state_machine.c:424
(sofia/internal/1001@85.16.246.12:5061) State DESTROY
2009-10-19 17:27:24.581127 [DEBUG] mod_sofia.c:261
sofia/internal/1001@85.16.246.12:5061 SOFIA DESTROY
2009-10-19 17:27:24.581127 [DEBUG] switch_core_state_machine.c:60
sofia/internal/1001@85.16.246.12:5061 Standard DESTROY
2009-10-19 17:27:24.581127 [DEBUG] switch_core_state_machine.c:424
(sofia/internal/1001@85.16.246.12:5061) State DESTROY going to sleep

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.7 (MingW32)

iD8DBQFK3IW/4tZeNddg3dwRAhrgAJ49KN/qc6Mqol2HC8JOVw6CxgU3MQCePJY7
or8ESeZIzc4ZkMqaUJLxzUQ=
=P2wM
-----END PGP SIGNATURE-----

Re: [Freeswitch-users] Qustion about INFO messages after Connect/Answer

Helmut Kuper