[Freeswitch-users] Qustion about INFO messages after Connect/Answer
Helmut Kuper
helmut.kuper at ewetel.de
Thu Oct 22 08:44:52 PDT 2009
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Hi Mike,
here it is:
Dialplan:
<extension name="Local_Extension">
<condition field="destination_number" expression="^(10[01][0-9])$">
<action application="set" data="dialed_extension=$1"/>
<action application="export" data="dialed_extension=$1"/>
<action application="set" data="transfer_ringback=$${hold_music}"/>
<action application="set" data="hangup_after_bridge=true"/>
<action application="bridge"
data="user/${dialed_extension}@${domain_name}"/>
</condition>
</extension>
Debug-Log:
recv 1521 bytes from udp/[85.16.245.206]:1024 at 15:41:02.405834:
------------------------------------------------------------------------
INVITE sip:1000 at 85.16.246.12:5061;user=phone SIP/2.0
Via: SIP/2.0/UDP 85.16.245.206:1024;branch=z9hG4bK-i48n75d62qts;rport
From: "1001 an PBX1" <sip:1001 at 85.16.246.12:5061>;tag=7xpim4o1go
To: <sip:1000 at 85.16.246.12:5061;user=phone>
Call-ID: 3c31304b7a80-no9xsnjj0bol
CSeq: 1 INVITE
Max-Forwards: 70
Contact: <sip:1001 at 85.16.245.206:1024;line=eg3wp69a>;reg-id=1
X-Serialnumber: 0004134002CB
P-Key-Flags: resolution="31x13", keys="4"
User-Agent: snom820/8.2.16
Accept: application/sdp
Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE,
PRACK, MESSAGE, INFO, UPDATE
Allow-Events: talk, hold, refer, call-info
Supported: timer, 100rel, replaces, from-change
Session-Expires: 3600;refresher=uas
Min-SE: 90
Content-Type: application/sdp
Content-Length: 732
v=0
o=root 411395140 411395140 IN IP4 85.16.245.206
s=call
c=IN IP4 85.16.245.206
t=0 0
m=audio 49852 RTP/SAVP 0 8 9 99 3 18 4 101
a=crypto:1 AES_CM_128_HMAC_SHA1_32
inline:Um06txYC7vwXdZDohXJ15te5hZ/iWmPd4voRbdby
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
a=sendrecv
m=audio 49852 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
a=sendrecv
------------------------------------------------------------------------
send 331 bytes to udp/[85.16.245.206]:1024 at 15:41:02.406500:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP
85.16.245.206:1024;branch=z9hG4bK-i48n75d62qts;rport=1024
From: "1001 an PBX1" <sip:1001 at 85.16.246.12:5061>;tag=7xpim4o1go
To: <sip:1000 at 85.16.246.12:5061;user=phone>
Call-ID: 3c31304b7a80-no9xsnjj0bol
CSeq: 1 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-15180M
Content-Length: 0
------------------------------------------------------------------------
2009-10-22 17:41:02.406509 [DEBUG] sofia.c:4907 IP 85.16.245.206
Approved by acl "clients[]". Access Granted.
2009-10-22 17:41:02.406509 [NOTICE] switch_channel.c:613 New Channel
sofia/internal/1001 at 85.16.246.12:5061 [4d941750-bf21-11de-9c3f-adfc1789590a]
2009-10-22 17:41:02.407509 [DEBUG] sofia.c:3493 Channel
sofia/internal/1001 at 85.16.246.12:5061 entering state [received][100]
2009-10-22 17:41:02.407509 [DEBUG] sofia.c:3500 Remote SDP:
v=0
o=root 411395140 411395140 IN IP4 85.16.245.206
s=call
c=IN IP4 85.16.245.206
t=0 0
m=audio 49852 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:Um06txYC7vwXdZDohXJ15te5hZ/iWmPd4voRbdby
a=ptime:20
m=audio 49852 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-22 17:41:02.407509 [DEBUG] sofia.c:3621
(sofia/internal/1001 at 85.16.246.12:5061) State Change CS_NEW -> CS_INIT
2009-10-22 17:41:02.407509 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:02.407509 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001 at 85.16.246.12:5061) Running State Change CS_INIT
2009-10-22 17:41:02.407509 [DEBUG] switch_core_state_machine.c:330
(sofia/internal/1001 at 85.16.246.12:5061) State INIT
2009-10-22 17:41:02.407509 [DEBUG] mod_sofia.c:83
sofia/internal/1001 at 85.16.246.12:5061 SOFIA INIT
2009-10-22 17:41:02.407509 [DEBUG] mod_sofia.c:111
(sofia/internal/1001 at 85.16.246.12:5061) State Change CS_INIT -> CS_ROUTING
2009-10-22 17:41:02.407509 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:02.407509 [DEBUG] switch_core_state_machine.c:330
(sofia/internal/1001 at 85.16.246.12:5061) State INIT going to sleep
2009-10-22 17:41:02.407509 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001 at 85.16.246.12:5061) Running State Change CS_ROUTING
2009-10-22 17:41:02.407509 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/1001 at 85.16.246.12:5061) State ROUTING
2009-10-22 17:41:02.407509 [DEBUG] mod_sofia.c:130
sofia/internal/1001 at 85.16.246.12:5061 SOFIA ROUTING
2009-10-22 17:41:02.407509 [DEBUG] switch_core_state_machine.c:78
sofia/internal/1001 at 85.16.246.12:5061 Standard ROUTING
2009-10-22 17:41:02.407509 [INFO] mod_dialplan_xml.c:391 Processing 1001
an PBX1->1000 in context default
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->anonymous] continue=true
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [anonymous]
destination_number(1000) =~ /^\*31([0-9]+)$/ break=never
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 ANTI-Action
set(dialed_extension=${destination_number})
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->is_local] continue=true
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [is_local]
${ET_is_local}() =~ /(true|false)/ break=on-true
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 ANTI-Action
lua(ET_is_local.lua)
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 ANTI-Action
transfer(${destination_number} XML default)
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->set_domain] continue=true
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (PASS)
[set_domain] destination_number(1000) =~ /^.*$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Action
set(domain_name=85.16.246.12)
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->302_zero_problem] continue=true
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL)
[302_zero_problem] ${sip_looped_call}() =~ /true/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->fakeTrisko-Servicenumber as callerid] continue=true
Dialplan: sofia/internal/1001 at 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 at 85.16.246.12:5061 parsing
[default->outbound-ssw-ddi] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL)
[outbound-ssw-ddi] ${dialed_extension}() =~ /^0([0-9]+)$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing [default->mail]
continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [mail]
destination_number(1000) =~ /^9997$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing [default->pizza]
continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [pizza]
destination_number(1000) =~ /^2006$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing [default->pbook]
continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [pbook]
destination_number(1000) =~ /^2007$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->shout_1] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [shout_1]
${dialed_extension}() =~ /^9123$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->shout_2] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [shout_2]
${dialed_extension}() =~ /^9124$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->speex_32000] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL)
[speex_32000] ${dialed_extension}() =~ /^9125$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->speex_32000_2] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL)
[speex_32000_2] ${dialed_extension}() =~ /^9126$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->jukebox] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [jukebox]
destination_number(1000) =~ /^9111$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->pickup-extension] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL)
[pickup-extension] ${dialed_extension}() =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->Voicemail-Verwaltung] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL)
[Voicemail-Verwaltung] ${dialed_extension}() =~ /^(1001|9999)$/
break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->Local_Extension] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL)
[Local_Extension] ${ET_is_local}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->parallel call] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [parallel
call] ${dialed_extension}() =~ /^(6000)$/ break=on-false
2009-10-22 17:41:02.409510 [DEBUG] switch_core_state_machine.c:114
(sofia/internal/1001 at 85.16.246.12:5061) State Change CS_ROUTING ->
CS_EXECUTE
2009-10-22 17:41:02.409510 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:02.409510 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/1001 at 85.16.246.12:5061) State ROUTING going to sleep
2009-10-22 17:41:02.409510 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001 at 85.16.246.12:5061) Running State Change CS_EXECUTE
2009-10-22 17:41:02.409510 [DEBUG] switch_core_state_machine.c:340
(sofia/internal/1001 at 85.16.246.12:5061) State EXECUTE
2009-10-22 17:41:02.409510 [DEBUG] mod_sofia.c:173
sofia/internal/1001 at 85.16.246.12:5061 SOFIA EXECUTE
2009-10-22 17:41:02.409510 [DEBUG] switch_core_state_machine.c:151
sofia/internal/1001 at 85.16.246.12:5061 Standard EXECUTE
EXECUTE sofia/internal/1001 at 85.16.246.12:5061 set(dialed_extension=1000)
2009-10-22 17:41:02.409510 [DEBUG] mod_dptools.c:752
sofia/internal/1001 at 85.16.246.12:5061 SET [dialed_extension]=[1000]
EXECUTE sofia/internal/1001 at 85.16.246.12:5061 lua(ET_is_local.lua)
2009-10-22 17:41:02.434510 [DEBUG] switch_cpp.cpp:925 destroy/unlink
session from object
EXECUTE sofia/internal/1001 at 85.16.246.12:5061 transfer(1000 XML default)
2009-10-22 17:41:02.434510 [DEBUG] switch_ivr.c:1381
(sofia/internal/1001 at 85.16.246.12:5061) State Change CS_EXECUTE ->
CS_ROUTING
2009-10-22 17:41:02.434510 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:02.434510 [DEBUG] switch_ivr.c:1385
sofia/internal/1001 at 85.16.246.12:5061 receive message [TRANSFER]
2009-10-22 17:41:02.434510 [DEBUG] switch_core_session.c:647 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:02.434510 [NOTICE] switch_ivr.c:1387 Transfer
sofia/internal/1001 at 85.16.246.12:5061 to XML[1000 at default]
2009-10-22 17:41:02.435510 [DEBUG] switch_core_state_machine.c:340
(sofia/internal/1001 at 85.16.246.12:5061) State EXECUTE going to sleep
2009-10-22 17:41:02.435510 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001 at 85.16.246.12:5061) Running State Change CS_ROUTING
2009-10-22 17:41:02.435510 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/1001 at 85.16.246.12:5061) State ROUTING
2009-10-22 17:41:02.435510 [DEBUG] mod_sofia.c:130
sofia/internal/1001 at 85.16.246.12:5061 SOFIA ROUTING
2009-10-22 17:41:02.435510 [DEBUG] switch_core_state_machine.c:78
sofia/internal/1001 at 85.16.246.12:5061 Standard ROUTING
2009-10-22 17:41:02.435510 [INFO] mod_dialplan_xml.c:391 Processing 1001
an PBX1->1000 in context default
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->anonymous] continue=true
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [anonymous]
destination_number(1000) =~ /^\*31([0-9]+)$/ break=never
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 ANTI-Action
set(dialed_extension=${destination_number})
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->is_local] continue=true
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (PASS) [is_local]
${ET_is_local}(true) =~ /(true|false)/ break=on-true
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->set_domain] continue=true
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (PASS)
[set_domain] destination_number(1000) =~ /^.*$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Action
set(domain_name=85.16.246.12)
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->302_zero_problem] continue=true
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL)
[302_zero_problem] ${sip_looped_call}() =~ /true/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->fakeTrisko-Servicenumber as callerid] continue=true
Dialplan: sofia/internal/1001 at 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 at 85.16.246.12:5061 parsing
[default->outbound-ssw-ddi] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL)
[outbound-ssw-ddi] ${dialed_extension}(1000) =~ /^0([0-9]+)$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing [default->mail]
continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [mail]
destination_number(1000) =~ /^9997$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing [default->pizza]
continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [pizza]
destination_number(1000) =~ /^2006$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing [default->pbook]
continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [pbook]
destination_number(1000) =~ /^2007$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->shout_1] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [shout_1]
${dialed_extension}(1000) =~ /^9123$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->shout_2] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [shout_2]
${dialed_extension}(1000) =~ /^9124$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->speex_32000] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL)
[speex_32000] ${dialed_extension}(1000) =~ /^9125$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->speex_32000_2] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL)
[speex_32000_2] ${dialed_extension}(1000) =~ /^9126$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->jukebox] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL) [jukebox]
destination_number(1000) =~ /^9111$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->pickup-extension] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL)
[pickup-extension] ${dialed_extension}(1000) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->Voicemail-Verwaltung] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (FAIL)
[Voicemail-Verwaltung] ${dialed_extension}(1000) =~ /^(1001|9999)$/
break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 parsing
[default->Local_Extension] continue=false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Regex (PASS)
[Local_Extension] ${ET_is_local}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Action
set(dialed_extension=${destination_number})
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Action
export(origination_callee_id_name=hubu)
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Action
export(dialed_extension=${destination_number})
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Action
set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Action
set(hangup_after_bridge=true)
Dialplan: sofia/internal/1001 at 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 at 85.16.246.12:5061 Action
db(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Action
set(continue_on_fail=false)
Dialplan: sofia/internal/1001 at 85.16.246.12:5061 Action
bridge(user/${dialed_extension}@85.16.246.12)
2009-10-22 17:41:02.436510 [DEBUG] switch_core_state_machine.c:114
(sofia/internal/1001 at 85.16.246.12:5061) State Change CS_ROUTING ->
CS_EXECUTE
2009-10-22 17:41:02.436510 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:02.436510 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/1001 at 85.16.246.12:5061) State ROUTING going to sleep
2009-10-22 17:41:02.436510 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001 at 85.16.246.12:5061) Running State Change CS_EXECUTE
2009-10-22 17:41:02.436510 [DEBUG] switch_core_state_machine.c:340
(sofia/internal/1001 at 85.16.246.12:5061) State EXECUTE
2009-10-22 17:41:02.436510 [DEBUG] mod_sofia.c:173
sofia/internal/1001 at 85.16.246.12:5061 SOFIA EXECUTE
2009-10-22 17:41:02.436510 [DEBUG] switch_core_state_machine.c:151
sofia/internal/1001 at 85.16.246.12:5061 Standard EXECUTE
EXECUTE sofia/internal/1001 at 85.16.246.12:5061 set(dialed_extension=1000)
2009-10-22 17:41:02.436510 [DEBUG] mod_dptools.c:752
sofia/internal/1001 at 85.16.246.12:5061 SET [dialed_extension]=[1000]
EXECUTE sofia/internal/1001 at 85.16.246.12:5061 set(domain_name=85.16.246.12)
2009-10-22 17:41:02.437526 [DEBUG] mod_dptools.c:752
sofia/internal/1001 at 85.16.246.12:5061 SET [domain_name]=[85.16.246.12]
EXECUTE sofia/internal/1001 at 85.16.246.12:5061 set(dialed_extension=1000)
2009-10-22 17:41:02.437526 [DEBUG] mod_dptools.c:752
sofia/internal/1001 at 85.16.246.12:5061 SET [dialed_extension]=[1000]
EXECUTE sofia/internal/1001 at 85.16.246.12:5061
export(origination_callee_id_name=hubu)
2009-10-22 17:41:02.437526 [DEBUG] mod_dptools.c:835 EXPORT
[origination_callee_id_name]=[hubu]
EXECUTE sofia/internal/1001 at 85.16.246.12:5061 export(dialed_extension=1000)
2009-10-22 17:41:02.437526 [DEBUG] mod_dptools.c:835 EXPORT
[dialed_extension]=[1000]
EXECUTE sofia/internal/1001 at 85.16.246.12:5061
set(transfer_ringback=local_stream://moh)
2009-10-22 17:41:02.438511 [DEBUG] mod_dptools.c:752
sofia/internal/1001 at 85.16.246.12:5061 SET
[transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/1001 at 85.16.246.12:5061 set(hangup_after_bridge=true)
2009-10-22 17:41:02.438511 [DEBUG] mod_dptools.c:752
sofia/internal/1001 at 85.16.246.12:5061 SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/1001 at 85.16.246.12:5061
export(nolocal:sip_secure_media=)
2009-10-22 17:41:02.461511 [DEBUG] mod_dptools.c:835 EXPORT (REMOTE
ONLY) [sip_secure_media]=[UNDEF]
EXECUTE sofia/internal/1001 at 85.16.246.12:5061
db(insert/85.16.246.12-last_dial//4d941750-bf21-11de-9c3f-adfc1789590a)
EXECUTE sofia/internal/1001 at 85.16.246.12:5061 set(continue_on_fail=false)
2009-10-22 17:41:02.654513 [DEBUG] mod_dptools.c:752
sofia/internal/1001 at 85.16.246.12:5061 SET [continue_on_fail]=[false]
EXECUTE sofia/internal/1001 at 85.16.246.12:5061 bridge(user/1000 at 85.16.246.12)
2009-10-22 17:41:02.679515 [DEBUG] switch_ivr_originate.c:1163 variable
string 0 = [presence_id=1000 at 85.16.246.12]
2009-10-22 17:41:02.679515 [NOTICE] switch_channel.c:613 New Channel
sofia/internal/sip:1000 at 85.16.245.228:1024
[4dbdc384-bf21-11de-9c3f-adfc1789590a]
2009-10-22 17:41:02.679515 [DEBUG] mod_sofia.c:2981
(sofia/internal/sip:1000 at 85.16.245.228:1024) State Change CS_NEW -> CS_INIT
2009-10-22 17:41:02.679515 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/sip:1000 at 85.16.245.228:1024 [BREAK]
2009-10-22 17:41:02.679515 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/sip:1000 at 85.16.245.228:1024) Running State Change CS_INIT
2009-10-22 17:41:02.680516 [DEBUG] switch_core_state_machine.c:330
(sofia/internal/sip:1000 at 85.16.245.228:1024) State INIT
2009-10-22 17:41:02.680516 [DEBUG] mod_sofia.c:83
sofia/internal/sip:1000 at 85.16.245.228:1024 SOFIA INIT
send 1310 bytes to udp/[85.16.245.228]:1024 at 15:41:02.681508:
------------------------------------------------------------------------
INVITE sip:1000 at 85.16.245.228:1024;line=5jkc7koy SIP/2.0
Via: SIP/2.0/UDP 85.16.246.12:5061;rport;branch=z9hG4bKKXH41BcZjB8FS
Max-Forwards: 68
From: "1001 an PBX1" <sip:1001 at 85.16.246.12>;tag=HKSNX8D1pKy6K
To: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>
Call-ID: 251c312d-39c4-122d-3fbf-00144fe6907a
CSeq: 121994695 INVITE
Contact: <sip:mod_sofia at 85.16.246.12:5061>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-15180M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER,
REFER, UPDATE, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Allow-Events: talk, presence, dialog, call-info, sla,
include-session-description, presence.winfo, message-summary, refer
2009-10-22 17:41:02.681515 [DEBUG] mod_sofia.c:111
(sofia/internal/sip:1000 at 85.16.245.228:1024) State Change CS_INIT ->
CS_ROUTING
2009-10-22 17:41:02.681515 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/sip:1000 at 85.16.245.228:1024 [BREAK]
Content-Type: application/sdp
Content-Disposition: session
2009-10-22 17:41:02.681515 [DEBUG] switch_core_state_machine.c:330
(sofia/internal/sip:1000 at 85.16.245.228:1024) State INIT going to sleep
Content-Length: 325
X-Serialnumber: 0004134002CB
2009-10-22 17:41:02.681515 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/sip:1000 at 85.16.245.228:1024) Running State Change CS_ROUTING
P-Key-Flags: resolution="31x13", keys="4"
X-Actually-Support: UPDATE
Remote-Party-ID: "1001 an PBX1"
<sip:1001 at 85.16.246.12>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1256212358 1256212359 IN IP4 85.16.246.12
s=FreeSWITCH
c=IN IP4 85.16.246.12
t=0 0
m=audio 13704 RTP/AVP 95 103 9 8 101 13
a=rtpmap:95 CELT/48000
a=rtpmap:103 SPEEX/32000
a=rtpmap:9 G722/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:10
------------------------------------------------------------------------
2009-10-22 17:41:02.681515 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/sip:1000 at 85.16.245.228:1024) State ROUTING
2009-10-22 17:41:02.681515 [DEBUG] mod_sofia.c:130
sofia/internal/sip:1000 at 85.16.245.228:1024 SOFIA ROUTING
2009-10-22 17:41:02.681515 [DEBUG] switch_ivr_originate.c:66
(sofia/internal/sip:1000 at 85.16.245.228:1024) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2009-10-22 17:41:02.681515 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/sip:1000 at 85.16.245.228:1024 [BREAK]
2009-10-22 17:41:02.681515 [DEBUG] sofia.c:3493 Channel
sofia/internal/sip:1000 at 85.16.245.228:1024 entering state [calling][0]
2009-10-22 17:41:02.681515 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/sip:1000 at 85.16.245.228:1024) State ROUTING going to sleep
2009-10-22 17:41:02.681515 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/sip:1000 at 85.16.245.228:1024) Running State Change
CS_CONSUME_MEDIA
2009-10-22 17:41:02.681515 [DEBUG] switch_core_state_machine.c:352
(sofia/internal/sip:1000 at 85.16.245.228:1024) State CONSUME_MEDIA
2009-10-22 17:41:02.681515 [DEBUG] switch_core_state_machine.c:352
(sofia/internal/sip:1000 at 85.16.245.228:1024) State CONSUME_MEDIA going
to sleep
recv 521 bytes from udp/[85.16.245.228]:1024 at 15:41:02.706318:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 85.16.246.12:5061;rport=5061;branch=z9hG4bKKXH41BcZjB8FS
From: "1001 an PBX1" <sip:1001 at 85.16.246.12>;tag=HKSNX8D1pKy6K
To: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;tag=sdeidvhpxx
Call-ID: 251c312d-39c4-122d-3fbf-00144fe6907a
CSeq: 121994695 INVITE
Contact: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;reg-id=1
Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE,
PRACK, MESSAGE, INFO, UPDATE
Allow-Events: talk, hold, refer, call-info
Content-Length: 0
------------------------------------------------------------------------
2009-10-22 17:41:02.706514 [DEBUG] sofia.c:3493 Channel
sofia/internal/sip:1000 at 85.16.245.228:1024 entering state [proceeding][180]
2009-10-22 17:41:02.706514 [NOTICE] sofia.c:3557 Ring-Ready
sofia/internal/sip:1000 at 85.16.245.228:1024!
2009-10-22 17:41:02.706514 [DEBUG] switch_ivr_originate.c:388
sofia/internal/1001 at 85.16.246.12:5061 receive message [RINGING]
2009-10-22 17:41:02.706514 [NOTICE] mod_sofia.c:1525 Ring-Ready
sofia/internal/1001 at 85.16.246.12:5061!
2009-10-22 17:41:02.706514 [DEBUG] switch_core_session.c:647 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:02.706514 [NOTICE] switch_ivr_originate.c:388 Ring
Ready sofia/internal/1001 at 85.16.246.12:5061!
send 737 bytes to udp/[85.16.245.206]:1024 at 15:41:02.706945:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP
85.16.245.206:1024;branch=z9hG4bK-i48n75d62qts;rport=1024
From: "1001 an PBX1" <sip:1001 at 85.16.246.12:5061>;tag=7xpim4o1go
To: <sip:1000 at 85.16.246.12:5061;user=phone>;tag=ga0vUDXXSa8Kr
Call-ID: 3c31304b7a80-no9xsnjj0bol
CSeq: 1 INVITE
Contact: <sip:1000 at 85.16.246.12:5061;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-15180M
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER,
REFER, UPDATE, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Allow-Events: talk, presence, dialog, call-info, sla,
include-session-description, presence.winfo, message-summary, refer
Content-Length: 0
X-Actually-Support: UPDATE
------------------------------------------------------------------------
2009-10-22 17:41:02.706514 [DEBUG] sofia.c:3493 Channel
sofia/internal/1001 at 85.16.246.12:5061 entering state [early][180]
recv 521 bytes from udp/[85.16.245.228]:1024 at 15:41:03.203506:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 85.16.246.12:5061;rport=5061;branch=z9hG4bKKXH41BcZjB8FS
From: "1001 an PBX1" <sip:1001 at 85.16.246.12>;tag=HKSNX8D1pKy6K
To: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;tag=sdeidvhpxx
Call-ID: 251c312d-39c4-122d-3fbf-00144fe6907a
CSeq: 121994695 INVITE
Contact: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;reg-id=1
Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE,
PRACK, MESSAGE, INFO, UPDATE
Allow-Events: talk, hold, refer, call-info
Content-Length: 0
------------------------------------------------------------------------
2009-10-22 17:41:03.203522 [DEBUG] sofia.c:3493 Channel
sofia/internal/sip:1000 at 85.16.245.228:1024 entering state [proceeding][180]
recv 521 bytes from udp/[85.16.245.228]:1024 at 15:41:04.203621:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 85.16.246.12:5061;rport=5061;branch=z9hG4bKKXH41BcZjB8FS
From: "1001 an PBX1" <sip:1001 at 85.16.246.12>;tag=HKSNX8D1pKy6K
To: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;tag=sdeidvhpxx
Call-ID: 251c312d-39c4-122d-3fbf-00144fe6907a
CSeq: 121994695 INVITE
Contact: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;reg-id=1
Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE,
PRACK, MESSAGE, INFO, UPDATE
Allow-Events: talk, hold, refer, call-info
Content-Length: 0
------------------------------------------------------------------------
2009-10-22 17:41:04.203541 [DEBUG] sofia.c:3493 Channel
sofia/internal/sip:1000 at 85.16.245.228:1024 entering state [proceeding][180]
recv 888 bytes from udp/[85.16.245.228]:1024 at 15:41:04.773115:
------------------------------------------------------------------------
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 85.16.246.12:5061;rport=5061;branch=z9hG4bKKXH41BcZjB8FS
From: "1001 an PBX1" <sip:1001 at 85.16.246.12>;tag=HKSNX8D1pKy6K
To: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;tag=sdeidvhpxx
Call-ID: 251c312d-39c4-122d-3fbf-00144fe6907a
CSeq: 121994695 INVITE
Contact: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;reg-id=1
User-Agent: snom820/LAB_HD_HEAD_11_09_09_11_20
Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE,
PRACK, MESSAGE, INFO, UPDATE
Allow-Events: talk, hold, refer, call-info
Supported: timer, 100rel, replaces, from-change
Content-Type: application/sdp
Content-Length: 242
v=0
o=root 45628059 45628060 IN IP4 85.16.245.228
s=call
c=IN IP4 85.16.245.228
t=0 0
m=audio 53220 RTP/AVP 9 8 101
a=rtpmap:9 g722/8000
a=rtpmap:8 pcma/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:10
a=sendrecv
------------------------------------------------------------------------
send 404 bytes to udp/[85.16.245.228]:1024 at 15:41:04.773445:
------------------------------------------------------------------------
ACK sip:1000 at 85.16.245.228:1024;line=5jkc7koy SIP/2.0
Via: SIP/2.0/UDP 85.16.246.12:5061;rport;branch=z9hG4bKm6aX36v2Fmy2m
Max-Forwards: 70
From: "1001 an PBX1" <sip:1001 at 85.16.246.12>;tag=HKSNX8D1pKy6K
To: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;tag=sdeidvhpxx
Call-ID: 251c312d-39c4-122d-3fbf-00144fe6907a
CSeq: 121994695 ACK
Contact: <sip:mod_sofia at 85.16.246.12:5061>
Content-Length: 0
------------------------------------------------------------------------
2009-10-22 17:41:04.773545 [DEBUG] sofia.c:3493 Channel
sofia/internal/sip:1000 at 85.16.245.228:1024 entering state [ready][200]
2009-10-22 17:41:04.773545 [DEBUG] sofia.c:3500 Remote SDP:
v=0
o=root 45628059 45628060 IN IP4 85.16.245.228
s=call
c=IN IP4 85.16.245.228
t=0 0
m=audio 53220 RTP/AVP 9 8 101
a=rtpmap:9 g722/8000
a=rtpmap:8 pcma/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:10
2009-10-22 17:41:04.773545 [DEBUG] sofia_glue.c:3143 Audio Codec Compare
[g722:9:8000:10]/[CELT:95:48000:10]
2009-10-22 17:41:04.773545 [DEBUG] sofia_glue.c:3143 Audio Codec Compare
[g722:9:8000:10]/[SPEEX:103:32000:20]
2009-10-22 17:41:04.773545 [DEBUG] sofia_glue.c:3143 Audio Codec Compare
[g722:9:8000:10]/[G722:9:8000:20]
2009-10-22 17:41:04.773545 [DEBUG] sofia_glue.c:3143 Audio Codec Compare
[g722:9:8000:10]/[PCMA:8:8000:20]
2009-10-22 17:41:04.773545 [DEBUG] sofia_glue.c:3191 Substituting codec
G722 at 10i@8000h
2009-10-22 17:41:04.773545 [DEBUG] sofia_glue.c:2101 Set Codec
sofia/internal/sip:1000 at 85.16.245.228:1024 G722/8000 10 ms 80 samples
2009-10-22 17:41:04.773545 [DEBUG] sofia_glue.c:3103 Set 2833 dtmf
payload to 101
2009-10-22 17:41:04.773545 [DEBUG] sofia_glue.c:2335 AUDIO RTP
[sofia/internal/sip:1000 at 85.16.245.228:1024] 85.16.246.12 port 13704 ->
85.16.245.228 port 53220 codec: 9 ms: 10
2009-10-22 17:41:04.773545 [DEBUG] switch_rtp.c:1155 Starting timer
[soft] 80 bytes per 10ms
2009-10-22 17:41:04.774778 [DEBUG] switch_channel.c:2105 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:04.774778 [NOTICE] sofia.c:3983 Channel
[sofia/internal/sip:1000 at 85.16.245.228:1024] has been answered
2009-10-22 17:41:04.774778 [DEBUG] switch_channel.c:182
sofia/internal/sip:1000 at 85.16.245.228:1024 receive message [AUDIO_SYNC]
2009-10-22 17:41:04.776545 [DEBUG] switch_ivr_originate.c:2324
sofia/internal/1001 at 85.16.246.12:5061 receive message [ANSWER]
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:3029 Set Remote Key [1
AES_CM_128_HMAC_SHA1_32 inline:Um06txYC7vwXdZDohXJ15te5hZ/iWmPd4voRbdby]
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:2161 Set Local Key [1
AES_CM_128_HMAC_SHA1_32 inline:EKycEU2CPLFUVM4vFRATL21nluVg3RJhmVwJVwA9]
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:3143 Audio Codec Compare
[pcmu:0:8000:20]/[CELT:95:48000:10]
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:3143 Audio Codec Compare
[pcmu:0:8000:20]/[SPEEX:103:32000:20]
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:3143 Audio Codec Compare
[pcmu:0:8000:20]/[G722:9:8000:20]
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:3143 Audio Codec Compare
[pcmu:0:8000:20]/[PCMA:8:8000:20]
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:3143 Audio Codec Compare
[pcma:8:8000:20]/[CELT:95:48000:10]
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:3143 Audio Codec Compare
[pcma:8:8000:20]/[SPEEX:103:32000:20]
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:3143 Audio Codec Compare
[pcma:8:8000:20]/[G722:9:8000:20]
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:3143 Audio Codec Compare
[pcma:8:8000:20]/[PCMA:8:8000:20]
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:2101 Set Codec
sofia/internal/1001 at 85.16.246.12:5061 PCMA/8000 20 ms 160 samples
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:3103 Set 2833 dtmf
payload to 101
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:3077 Our existing sdp is
still good [pcma 85.16.245.206:49852], let's keep it.
2009-10-22 17:41:04.776545 [DEBUG] sofia_glue.c:2335 AUDIO RTP
[sofia/internal/1001 at 85.16.246.12:5061] 85.16.246.12 port 10062 ->
85.16.245.206 port 49852 codec: 8 ms: 20
2009-10-22 17:41:04.776545 [DEBUG] switch_rtp.c:1155 Starting timer
[soft] 160 bytes per 20ms
2009-10-22 17:41:04.778545 [INFO] switch_rtp.c:1019 Activating Secure
RTP SEND
2009-10-22 17:41:04.778545 [INFO] switch_rtp.c:999 Activating Secure RTP
RECV
2009-10-22 17:41:04.778545 [DEBUG] switch_core_sqldb.c:396 Secure Type:
srtp:AES_CM_128_HMAC_SHA1_32
2009-10-22 17:41:04.778545 [DEBUG] switch_core_sqldb.c:396 Secure Type:
srtp:AES_CM_128_HMAC_SHA1_32
2009-10-22 17:41:04.778545 [NOTICE] sofia_glue.c:2770 Pre-Answer
sofia/internal/1001 at 85.16.246.12:5061!
2009-10-22 17:41:04.778545 [DEBUG] mod_sofia.c:543 Local SDP
sofia/internal/1001 at 85.16.246.12:5061:
v=0
o=FreeSWITCH 1256216002 1256216003 IN IP4 85.16.246.12
s=FreeSWITCH
c=IN IP4 85.16.246.12
t=0 0
m=audio 10062 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:EKycEU2CPLFUVM4vFRATL21nluVg3RJhmVwJVwA9
2009-10-22 17:41:04.778545 [DEBUG] switch_core_session.c:647 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:04.778545 [NOTICE] switch_ivr_originate.c:2324 Channel
[sofia/internal/1001 at 85.16.246.12:5061] has been answered
2009-10-22 17:41:04.778545 [DEBUG] switch_channel.c:182
sofia/internal/1001 at 85.16.246.12:5061 receive message [AUDIO_SYNC]
2009-10-22 17:41:04.778545 [DEBUG] switch_ivr_originate.c:2368 Originate
Resulted in Success: [sofia/internal/sip:1000 at 85.16.245.228:1024]
2009-10-22 17:41:04.778545 [DEBUG] switch_channel.c:182
sofia/internal/sip:1000 at 85.16.245.228:1024 receive message [AUDIO_SYNC]
2009-10-22 17:41:04.778545 [DEBUG] switch_channel.c:182
sofia/internal/1001 at 85.16.246.12:5061 receive message [AUDIO_SYNC]
send 1174 bytes to udp/[85.16.245.206]:1024 at 15:41:04.779182:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP
85.16.245.206:1024;branch=z9hG4bK-i48n75d62qts;rport=1024
From: "1001 an PBX1" <sip:1001 at 85.16.246.12:5061>;tag=7xpim4o1go
To: <sip:1000 at 85.16.246.12:5061;user=phone>;tag=ga0vUDXXSa8Kr
Call-ID: 3c31304b7a80-no9xsnjj0bol
CSeq: 1 INVITE
Contact: <sip:1000 at 85.16.246.12:5061;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-15180M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER,
REFER, UPDATE, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Allow-Events: talk, presence, dialog, call-info, sla,
include-session-description, presence.winfo, message-summary, refer
Session-Expires: 3600;refresher=uas
Min-SE: 120
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 354
X-Actually-Support: UPDATE
v=0
o=FreeSWITCH 1256216002 1256216003 IN IP4 85.16.246.12
s=FreeSWITCH
c=IN IP4 85.16.246.12
t=0 0
m=audio 10062 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=crypto:1 AES_CM_128_HMAC_SHA1_32
inline:EKycEU2CPLFUVM4vFRATL21nluVg3RJhmVwJVwA9
m=audio 0 RTP/AVP 19
------------------------------------------------------------------------
2009-10-22 17:41:04.778545 [DEBUG] sofia.c:3493 Channel
sofia/internal/1001 at 85.16.246.12:5061 entering state [completed][200]
2009-10-22 17:41:04.778545 [DEBUG] sofia.c:407
sofia/internal/sip:1000 at 85.16.245.228:1024 receive message [DISPLAY]
send 674 bytes to udp/[85.16.245.228]:1024 at 15:41:04.779630:
------------------------------------------------------------------------
INFO sip:1000 at 85.16.245.228:1024;line=5jkc7koy SIP/2.0
Via: SIP/2.0/UDP 85.16.246.12:5061;rport;branch=z9hG4bKNF4N51D6cXmNg
Max-Forwards: 70
From: "1001 an PBX1" <sip:1001 at 85.16.246.12>;tag=HKSNX8D1pKy6K
To: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;tag=sdeidvhpxx
2009-10-22 17:41:04.779555 [DEBUG] switch_ivr_originate.c:2368 Originate
Resulted in Success: [sofia/internal/sip:1000 at 85.16.245.228:1024]
Call-ID: 251c312d-39c4-122d-3fbf-00144fe6907a
CSeq: 121994696 INFO
Contact: <sip:mod_sofia at 85.16.246.12:5061>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-15180M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER,
REFER, UPDATE, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Content-Type: message/sipfrag
Content-Length: 27
2009-10-22 17:41:04.779555 [DEBUG] switch_channel.c:182
sofia/internal/sip:1000 at 85.16.245.228:1024 receive message [AUDIO_SYNC]
From:
To: "unknown" 1000
------------------------------------------------------------------------
2009-10-22 17:41:04.779555 [DEBUG] switch_channel.c:182
sofia/internal/1001 at 85.16.246.12:5061 receive message [AUDIO_SYNC]
2009-10-22 17:41:04.779555 [DEBUG] switch_ivr_bridge.c:975
sofia/internal/sip:1000 at 85.16.245.228:1024 receive message [BRIDGE]
2009-10-22 17:41:04.779555 [DEBUG] switch_core_session.c:647 Send signal
sofia/internal/sip:1000 at 85.16.245.228:1024 [BREAK]
2009-10-22 17:41:04.779555 [DEBUG] switch_ivr_bridge.c:982
sofia/internal/1001 at 85.16.246.12:5061 receive message [BRIDGE]
2009-10-22 17:41:04.779555 [DEBUG] switch_core_session.c:647 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:04.779555 [DEBUG] switch_ivr_bridge.c:1026
(sofia/internal/sip:1000 at 85.16.245.228:1024) State Change
CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2009-10-22 17:41:04.779555 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/sip:1000 at 85.16.245.228:1024 [BREAK]
2009-10-22 17:41:04.779555 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/sip:1000 at 85.16.245.228:1024) Running State Change
CS_EXCHANGE_MEDIA
2009-10-22 17:41:04.780562 [DEBUG] switch_core_state_machine.c:343
(sofia/internal/sip:1000 at 85.16.245.228:1024) State EXCHANGE_MEDIA
2009-10-22 17:41:04.780562 [DEBUG] mod_sofia.c:436 SOFIA LOOPBACK
recv 405 bytes from udp/[85.16.245.206]:1024 at 15:41:04.819062:
------------------------------------------------------------------------
ACK sip:1000 at 85.16.246.12:5061;transport=udp SIP/2.0
Via: SIP/2.0/UDP 85.16.245.206:1024;branch=z9hG4bK-ltlzbi82kr2t;rport
From: "1001 an PBX1" <sip:1001 at 85.16.246.12:5061>;tag=7xpim4o1go
To: <sip:1000 at 85.16.246.12:5061;user=phone>;tag=ga0vUDXXSa8Kr
Call-ID: 3c31304b7a80-no9xsnjj0bol
CSeq: 1 ACK
Max-Forwards: 70
Contact: <sip:1001 at 85.16.245.206:1024;line=eg3wp69a>;reg-id=1
Content-Length: 0
------------------------------------------------------------------------
2009-10-22 17:41:04.818545 [DEBUG] sofia.c:3493 Channel
sofia/internal/1001 at 85.16.246.12:5061 entering state [ready][200]
2009-10-22 17:41:04.830545 [DEBUG] switch_ivr_bridge.c:122
sofia/internal/sip:1000 at 85.16.245.228:1024 receive message [DISPLAY]
2009-10-22 17:41:04.840545 [DEBUG] switch_ivr_bridge.c:122
sofia/internal/1001 at 85.16.246.12:5061 receive message [DISPLAY]
send 670 bytes to udp/[85.16.245.206]:1024 at 15:41:04.840803:
------------------------------------------------------------------------
INFO sip:1001 at 85.16.245.206:1024;line=eg3wp69a SIP/2.0
Via: SIP/2.0/UDP 85.16.246.12:5061;rport;branch=z9hG4bKprXe7vy995a8B
Max-Forwards: 70
From: <sip:1000 at 85.16.246.12:5061;user=phone>;tag=ga0vUDXXSa8Kr
To: "1001 an PBX1" <sip:1001 at 85.16.246.12:5061>;tag=7xpim4o1go
Call-ID: 3c31304b7a80-no9xsnjj0bol
CSeq: 121994696 INFO
Contact: <sip:1000 at 85.16.246.12:5061;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-15180M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER,
REFER, UPDATE, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Content-Type: message/sipfrag
Content-Length: 24
From:
To: "hubu" 1000
------------------------------------------------------------------------
2009-10-22 17:41:04.860546 [DEBUG] switch_core_io.c:652
sofia/internal/sip:1000 at 85.16.245.228:1024 receive message
[TRANSCODING_NECESSARY]
2009-10-22 17:41:04.860546 [DEBUG] switch_core_io.c:891 Engaging Write
Buffer at 320 bytes to accommodate 640->320
2009-10-22 17:41:04.930547 [DEBUG] switch_core_io.c:652
sofia/internal/1001 at 85.16.246.12:5061 receive message
[TRANSCODING_NECESSARY]
2009-10-22 17:41:04.930547 [DEBUG] switch_core_io.c:891 Engaging Write
Buffer at 320 bytes to accommodate 320->320
2009-10-22 17:41:05.000550 [WARNING] mod_sofia.c:808 We were told to use
ptime 10 but what they meant to say was 20
This issue has so far been identified to happen on the following broken
platforms/devices:
Linksys/Sipura aka Cisco
ShoreTel
Sonus/L3
We will try to fix it but some of the devices on this list are so broken
who knows what will happen..
2009-10-22 17:41:05.000550 [DEBUG] sofia_glue.c:2101 Set Codec
sofia/internal/sip:1000 at 85.16.245.228:1024 G722/8000 20 ms 160 samples
2009-10-22 17:41:05.000550 [DEBUG] switch_rtp.c:1064 RE-Starting timer
[soft] 160 bytes per 20000ms
recv 362 bytes from udp/[85.16.245.206]:1024 at 15:41:05.019892:
------------------------------------------------------------------------
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 85.16.246.12:5061;rport=5061;branch=z9hG4bKprXe7vy995a8B
From: <sip:1000 at 85.16.246.12:5061;user=phone>;tag=ga0vUDXXSa8Kr
To: "1001 an PBX1" <sip:1001 at 85.16.246.12:5061>;tag=7xpim4o1go
Call-ID: 3c31304b7a80-no9xsnjj0bol
CSeq: 121994696 INFO
Contact: <sip:1001 at 85.16.245.206:1024;line=eg3wp69a>;reg-id=1
Content-Length: 0
------------------------------------------------------------------------
recv 372 bytes from udp/[85.16.245.228]:1024 at 15:41:05.177982:
------------------------------------------------------------------------
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 85.16.246.12:5061;rport=5061;branch=z9hG4bKNF4N51D6cXmNg
From: "1001 an PBX1" <sip:1001 at 85.16.246.12>;tag=HKSNX8D1pKy6K
To: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;tag=sdeidvhpxx
Call-ID: 251c312d-39c4-122d-3fbf-00144fe6907a
CSeq: 121994696 INFO
Contact: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;reg-id=1
Content-Length: 0
------------------------------------------------------------------------
send 679 bytes to udp/[85.16.245.228]:1024 at 15:41:05.178268:
------------------------------------------------------------------------
INFO sip:1000 at 85.16.245.228:1024;line=5jkc7koy SIP/2.0
Via: SIP/2.0/UDP 85.16.246.12:5061;rport;branch=z9hG4bKQ1p78QFD7e1tQ
Max-Forwards: 70
From: "1001 an PBX1" <sip:1001 at 85.16.246.12>;tag=HKSNX8D1pKy6K
To: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;tag=sdeidvhpxx
Call-ID: 251c312d-39c4-122d-3fbf-00144fe6907a
CSeq: 121994697 INFO
Contact: <sip:mod_sofia at 85.16.246.12:5061>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-15180M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER,
REFER, UPDATE, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Content-Type: message/sipfrag
Content-Length: 32
From:
To: "1001 an PBX1" 1001
------------------------------------------------------------------------
recv 372 bytes from udp/[85.16.245.228]:1024 at 15:41:05.271275:
------------------------------------------------------------------------
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 85.16.246.12:5061;rport=5061;branch=z9hG4bKQ1p78QFD7e1tQ
From: "1001 an PBX1" <sip:1001 at 85.16.246.12>;tag=HKSNX8D1pKy6K
To: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;tag=sdeidvhpxx
Call-ID: 251c312d-39c4-122d-3fbf-00144fe6907a
CSeq: 121994697 INFO
Contact: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;reg-id=1
Content-Length: 0
------------------------------------------------------------------------
recv 589 bytes from udp/[85.16.245.228]:1024 at 15:41:06.336858:
------------------------------------------------------------------------
BYE sip:mod_sofia at 85.16.246.12:5061 SIP/2.0
Via: SIP/2.0/UDP 85.16.245.228:1024;branch=z9hG4bK-quadh3ddon5i;rport
From: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;tag=sdeidvhpxx
To: "1001 an PBX1" <sip:1001 at 85.16.246.12>;tag=HKSNX8D1pKy6K
Call-ID: 251c312d-39c4-122d-3fbf-00144fe6907a
CSeq: 1 BYE
Max-Forwards: 70
Contact: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;reg-id=1
User-Agent: snom820/LAB_HD_HEAD_11_09_09_11_20
RTP-RxStat:
Total_Rx_Pkts=0,Rx_Pkts=66,Rx_Pkts_Lost=1,Remote_Rx_Pkts_Lost=0
RTP-TxStat: Total_Tx_Pkts=67,Tx_Pkts=62,Remote_Tx_Pkts=0
Content-Length: 0
------------------------------------------------------------------------
2009-10-22 17:41:06.336568 [NOTICE] sofia.c:328 Hangup
sofia/internal/sip:1000 at 85.16.245.228:1024 [CS_EXCHANGE_MEDIA]
[NORMAL_CLEARING]
2009-10-22 17:41:06.336568 [DEBUG] switch_channel.c:1896 Send signal
sofia/internal/sip:1000 at 85.16.245.228:1024 [KILL]
2009-10-22 17:41:06.336568 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/sip:1000 at 85.16.245.228:1024 [BREAK]
2009-10-22 17:41:06.336568 [DEBUG] switch_core_state_machine.c:449
thread mismatch skipping state handler.
send 510 bytes to udp/[85.16.245.228]:1024 at 15:41:06.337536:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP
85.16.245.228:1024;branch=z9hG4bK-quadh3ddon5i;rport=1024
From: <sip:1000 at 85.16.245.228:1024;line=5jkc7koy>;tag=sdeidvhpxx
To: "1001 an PBX1" <sip:1001 at 85.16.246.12>;tag=HKSNX8D1pKy6K
Call-ID: 251c312d-39c4-122d-3fbf-00144fe6907a
CSeq: 1 BYE
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-15180M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER,
REFER, UPDATE, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Content-Length: 0
------------------------------------------------------------------------
2009-10-22 17:41:06.340568 [DEBUG] switch_ivr_bridge.c:453
sofia/internal/sip:1000 at 85.16.245.228:1024 ending bridge by request from
read function
2009-10-22 17:41:06.340568 [DEBUG] switch_ivr_bridge.c:447
sofia/internal/sip:1000 at 85.16.245.228:1024 ending bridge by request from
write function
2009-10-22 17:41:06.340568 [DEBUG] switch_ivr_bridge.c:528 BRIDGE THREAD
DONE [sofia/internal/sip:1000 at 85.16.245.228:1024]
2009-10-22 17:41:06.340568 [DEBUG] switch_ivr_bridge.c:530 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:06.340568 [DEBUG] switch_core_state_machine.c:343
(sofia/internal/sip:1000 at 85.16.245.228:1024) State EXCHANGE_MEDIA going
to sleep
2009-10-22 17:41:06.340568 [DEBUG] switch_ivr_bridge.c:502
sofia/internal/1001 at 85.16.246.12:5061 receive message [UNBRIDGE]
2009-10-22 17:41:06.340568 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/sip:1000 at 85.16.245.228:1024) Running State Change CS_HANGUP
2009-10-22 17:41:06.340568 [DEBUG] switch_core_session.c:647 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:06.340568 [DEBUG] switch_ivr_bridge.c:528 BRIDGE THREAD
DONE [sofia/internal/1001 at 85.16.246.12:5061]
2009-10-22 17:41:06.340568 [DEBUG] switch_ivr_bridge.c:530 Send signal
sofia/internal/sip:1000 at 85.16.245.228:1024 [BREAK]
2009-10-22 17:41:06.340568 [NOTICE] switch_ivr_bridge.c:1102 Hangup
sofia/internal/1001 at 85.16.246.12:5061 [CS_EXECUTE] [NORMAL_CLEARING]
2009-10-22 17:41:06.340568 [DEBUG] switch_channel.c:1896 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [KILL]
2009-10-22 17:41:06.340568 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:06.340568 [DEBUG] switch_core_state_machine.c:476
(sofia/internal/sip:1000 at 85.16.245.228:1024) State HANGUP
2009-10-22 17:41:06.340568 [DEBUG] mod_sofia.c:344 Channel
sofia/internal/sip:1000 at 85.16.245.228:1024 hanging up, cause:
NORMAL_CLEARING
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:46
sofia/internal/sip:1000 at 85.16.245.228:1024 Standard HANGUP, cause:
NORMAL_CLEARING
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:476
(sofia/internal/sip:1000 at 85.16.245.228:1024) State HANGUP going to sleep
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:325
(sofia/internal/sip:1000 at 85.16.245.228:1024) State Change CS_HANGUP ->
CS_REPORTING
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:476
(sofia/internal/1001 at 85.16.246.12:5061) State HANGUP
2009-10-22 17:41:06.341609 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/sip:1000 at 85.16.245.228:1024 [BREAK]
2009-10-22 17:41:06.341609 [DEBUG] mod_sofia.c:344 Channel
sofia/internal/1001 at 85.16.246.12:5061 hanging up, cause: NORMAL_CLEARING
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/sip:1000 at 85.16.245.228:1024) Running State Change
CS_REPORTING
2009-10-22 17:41:06.341609 [DEBUG] mod_sofia.c:382 Sending BYE to
sofia/internal/1001 at 85.16.246.12:5061
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:567
(sofia/internal/sip:1000 at 85.16.245.228:1024) State REPORTING
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:53
sofia/internal/sip:1000 at 85.16.245.228:1024 Standard REPORTING, cause:
NORMAL_CLEARING
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:567
(sofia/internal/sip:1000 at 85.16.245.228:1024) State REPORTING going to sleep
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:319
(sofia/internal/sip:1000 at 85.16.245.228:1024) State Change CS_REPORTING
- -> CS_DESTROY
2009-10-22 17:41:06.341609 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/sip:1000 at 85.16.245.228:1024 [BREAK]
2009-10-22 17:41:06.341609 [DEBUG] switch_core_session.c:1114 Session 42
(sofia/internal/sip:1000 at 85.16.245.228:1024) Locked, Waiting on external
entities
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:46
sofia/internal/1001 at 85.16.246.12:5061 Standard HANGUP, cause:
NORMAL_CLEARING
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:476
(sofia/internal/1001 at 85.16.246.12:5061) State HANGUP going to sleep
2009-10-22 17:41:06.341609 [NOTICE] switch_core_session.c:1132 Session
42 (sofia/internal/sip:1000 at 85.16.245.228:1024) Ended
2009-10-22 17:41:06.341609 [NOTICE] switch_core_session.c:1134 Close
Channel sofia/internal/sip:1000 at 85.16.245.228:1024 [CS_DESTROY]
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:413
(sofia/internal/sip:1000 at 85.16.245.228:1024) Running State Change CS_DESTROY
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:424
(sofia/internal/sip:1000 at 85.16.245.228:1024) State DESTROY
2009-10-22 17:41:06.341609 [DEBUG] mod_sofia.c:261
sofia/internal/sip:1000 at 85.16.245.228:1024 SOFIA DESTROY
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:340
(sofia/internal/1001 at 85.16.246.12:5061) State EXECUTE going to sleep
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001 at 85.16.246.12:5061) Running State Change CS_HANGUP
2009-10-22 17:41:06.342645 [DEBUG] switch_core_state_machine.c:454
handler already called, skipping state handler.
2009-10-22 17:41:06.341609 [DEBUG] switch_core_state_machine.c:60
sofia/internal/sip:1000 at 85.16.245.228:1024 Standard DESTROY
2009-10-22 17:41:06.342645 [DEBUG] switch_core_state_machine.c:424
(sofia/internal/sip:1000 at 85.16.245.228:1024) State DESTROY going to sleep
send 659 bytes to udp/[85.16.245.206]:1024 at 15:41:06.342919:
------------------------------------------------------------------------
BYE sip:1001 at 85.16.245.206:1024;line=eg3wp69a SIP/2.02009-10-22
17:41:06.342645 [DEBUG] switch_core_state_machine.c:325
(sofia/internal/1001 at 85.16.246.12:5061) State Change CS_HANGUP ->
CS_REPORTING
2009-10-22 17:41:06.342645 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:06.342645 [DEBUG] switch_core_state_machine.c:306
(sofia/internal/1001 at 85.16.246.12:5061) Running State Change CS_REPORTING
2009-10-22 17:41:06.342645 [DEBUG] switch_core_state_machine.c:567
(sofia/internal/1001 at 85.16.246.12:5061) State REPORTING
Via: SIP/2.0/UDP 85.16.246.12:5061;rport;branch=z9hG4bKrag0aK0g4QQDK
Max-Forwards: 70
From: <sip:1000 at 85.16.246.12:5061;user=phone>;tag=ga0vUDXXSa8Kr
To: "1001 an PBX1" <sip:1001 at 85.16.246.12:5061>;tag=7xpim4o1go
Call-ID: 3c31304b7a80-no9xsnjj0bol
CSeq: 121994697 BYE
Contact: <sip:1000 at 85.16.246.12:5061;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.0.trunk-15180M
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, REGISTER,
REFER, UPDATE, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0
------------------------------------------------------------------------
2009-10-22 17:41:06.343570 [DEBUG] switch_core_state_machine.c:53
sofia/internal/1001 at 85.16.246.12:5061 Standard REPORTING, cause:
NORMAL_CLEARING
2009-10-22 17:41:06.343570 [DEBUG] switch_core_state_machine.c:567
(sofia/internal/1001 at 85.16.246.12:5061) State REPORTING going to sleep
2009-10-22 17:41:06.343570 [DEBUG] switch_core_state_machine.c:319
(sofia/internal/1001 at 85.16.246.12:5061) State Change CS_REPORTING ->
CS_DESTROY
2009-10-22 17:41:06.343570 [DEBUG] switch_core_session.c:977 Send signal
sofia/internal/1001 at 85.16.246.12:5061 [BREAK]
2009-10-22 17:41:06.343570 [DEBUG] switch_core_session.c:1114 Session 41
(sofia/internal/1001 at 85.16.246.12:5061) Locked, Waiting on external entities
2009-10-22 17:41:06.343570 [NOTICE] switch_core_session.c:1132 Session
41 (sofia/internal/1001 at 85.16.246.12:5061) Ended
2009-10-22 17:41:06.343570 [NOTICE] switch_core_session.c:1134 Close
Channel sofia/internal/1001 at 85.16.246.12:5061 [CS_DESTROY]
2009-10-22 17:41:06.343570 [DEBUG] switch_core_state_machine.c:413
(sofia/internal/1001 at 85.16.246.12:5061) Running State Change CS_DESTROY
2009-10-22 17:41:06.343570 [DEBUG] switch_core_state_machine.c:424
(sofia/internal/1001 at 85.16.246.12:5061) State DESTROY
2009-10-22 17:41:06.343570 [DEBUG] mod_sofia.c:261
sofia/internal/1001 at 85.16.246.12:5061 SOFIA DESTROY
2009-10-22 17:41:06.343570 [DEBUG] switch_core_state_machine.c:60
sofia/internal/1001 at 85.16.246.12:5061 Standard DESTROY
2009-10-22 17:41:06.343570 [DEBUG] switch_core_state_machine.c:424
(sofia/internal/1001 at 85.16.246.12:5061) State DESTROY going to sleep
recv 524 bytes from udp/[85.16.245.206]:1024 at 15:41:06.357848:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 85.16.246.12:5061;rport=5061;branch=z9hG4bKrag0aK0g4QQDK
From: <sip:1000 at 85.16.246.12:5061;user=phone>;tag=ga0vUDXXSa8Kr
To: "1001 an PBX1" <sip:1001 at 85.16.246.12:5061>;tag=7xpim4o1go
Call-ID: 3c31304b7a80-no9xsnjj0bol
CSeq: 121994697 BYE
Contact: <sip:1001 at 85.16.245.206:1024;line=eg3wp69a>;reg-id=1
User-Agent: snom820/8.2.16
RTP-RxStat:
Total_Rx_Pkts=61,Rx_Pkts=61,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0
RTP-TxStat: Total_Tx_Pkts=0,Tx_Pkts=90,Remote_Tx_Pkts=0
Content-Length: 0
------------------------------------------------------------------------
On 21.10.2009 19:48, Michael Collins wrote:
>
> Okay, you are able to reproduce that "unknown" thing? Can you pastebin a
> fresh debug log w/ SIP trace on, plus and relevant dp changes from the
> default dialplan?
> Thanks,
> MC
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.7 (MingW32)
iD8DBQFK4H3z4tZeNddg3dwRAtR3AJ4xUr8Tp4ctmhQn2DIQSvrBSv59QQCeLSsH
5inLJYyajrsYT2+kXcgd22w=
=5B1x
-----END PGP SIGNATURE-----
More information about the FreeSWITCH-users
mailing list