[Freeswitch-users] presence in linksys spa932
Vladimir Elizarov
xengelpublicx at gmail.com
Fri Jun 18 02:47:32 PDT 2010
debug presence 192.168.0.220 - spa962, 192.168.50.11 - fs 1.0.6,
192.168.0.176 - spa921, 10.8.6.6 - twinkle: spa921 ringing twinkle.
spa921 status update, twinkle status not update
------------------------------------------------------------------------
send 937 bytes to udp/[192.168.0.220]:5060 at 09:29:28.504919:
------------------------------------------------------------------------
NOTIFY sip:100 at 192.168.0.220:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.50.11;rport;branch=z9hG4bK35tZKB43mmD7D
Max-Forwards: 70
From: <sip:229 at tssec.ru>;tag=Be64rve6FSU1D
To: <sip:100 at tssec.ru>;tag=beeaf51cf0d364d9
Call-ID: e2bc3098-8a58ff8d at 192.168.0.220
CSeq: 132308348 NOTIFY
Contact: <sip:229 at 192.168.50.11:5060>
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Event: dialog
Allow-Events: talk, hold, presence, dialog, line-seize, call-info,
sla, include-session-description, presence.winfo, message-summary,
refer
Subscription-State: active;expires=599
Content-Type: application/dialog-info+xml
Content-Length: 148
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="0"
state="partial" entity="sip:229 at tssec.ru">
</dialog-info>
------------------------------------------------------------------------
recv 285 bytes from udp/[192.168.0.220]:5060 at 09:29:28.516926:
------------------------------------------------------------------------
SIP/2.0 200 OK
To: <sip:100 at tssec.ru>;tag=beeaf51cf0d364d9
From: <sip:229 at tssec.ru>;tag=Be64rve6FSU1D
Call-ID: e2bc3098-8a58ff8d at 192.168.0.220
CSeq: 132308348 NOTIFY
Via: SIP/2.0/UDP 192.168.50.11;branch=z9hG4bK35tZKB43mmD7D
Server: Linksys/SPA962-6.1.3(a)
Content-Length: 0
------------------------------------------------------------------------
freeswitch at 192.168.50.11@internal> recv 927 bytes from
udp/[192.168.0.176]:5060 at 09:30:04.240224:
------------------------------------------------------------------------
INVITE sip:215 at tssec.ru SIP/2.0
Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-cd8a0332
From: "Nikolai Gabelok" <sip:229 at tssec.ru>;tag=1e57eac0cc8bf959o0
To: "Elizarov Vladimir" <sip:215 at tssec.ru>
Call-ID: b4d6c80c-3143dc7d at 192.168.0.176
CSeq: 101 INVITE
Max-Forwards: 70
Contact: "Nikolai Gabelok" <sip:229 at 192.168.0.176:5060>
Expires: 240
User-Agent: Linksys/SPA921-5.1.8
Content-Length: 401
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces
Content-Type: application/sdp
v=0
o=- 31175322 31175322 IN IP4 192.168.0.176
s=-
c=IN IP4 192.168.0.176
t=0 0
m=audio 16472 RTP/AVP 8 0 2 4 18 96 97 98 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
------------------------------------------------------------------------
send 321 bytes to udp/[192.168.0.176]:5060 at 09:30:04.240224:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-cd8a0332
From: "Nikolai Gabelok" <sip:229 at tssec.ru>;tag=1e57eac0cc8bf959o0
To: "Elizarov Vladimir" <sip:215 at tssec.ru>
Call-ID: b4d6c80c-3143dc7d at 192.168.0.176
CSeq: 101 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
Content-Length: 0
------------------------------------------------------------------------
2010-06-18 13:28:29.397241 [DEBUG] sofia.c:5949 IP 192.168.0.176
Rejected by acl "domains". Falling back to Digest auth.
send 804 bytes to udp/[192.168.0.176]:5060 at 09:30:04.252231:
------------------------------------------------------------------------
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-cd8a0332
From: "Nikolai Gabelok" <sip:229 at tssec.ru>;tag=1e57eac0cc8bf959o0
To: "Elizarov Vladimir" <sip:215 at tssec.ru>;tag=cQZXtQZ9c2HmS
Call-ID: b4d6c80c-3143dc7d at 192.168.0.176
CSeq: 101 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Allow-Events: talk, hold, presence, dialog, line-seize, call-info,
sla, include-session-description, presence.winfo, message-summary,
refer
Proxy-Authenticate: Digest realm="tssec.ru",
nonce="13679dc0-7abc-11df-97d3-6f7c82b8b4b4", algorithm=MD5,
qop="auth"
Content-Length: 0
------------------------------------------------------------------------
recv 407 bytes from udp/[192.168.0.176]:5060 at 09:30:04.276244:
------------------------------------------------------------------------
ACK sip:215 at tssec.ru SIP/2.0
Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-cd8a0332
From: "Nikolai Gabelok" <sip:229 at tssec.ru>;tag=1e57eac0cc8bf959o0
To: "Elizarov Vladimir" <sip:215 at tssec.ru>;tag=cQZXtQZ9c2HmS
Call-ID: b4d6c80c-3143dc7d at 192.168.0.176
CSeq: 101 ACK
Max-Forwards: 70
Contact: "Nikolai Gabelok" <sip:229 at 192.168.0.176:5060>
User-Agent: Linksys/SPA921-5.1.8
Content-Length: 0
------------------------------------------------------------------------
recv 1153 bytes from udp/[192.168.0.176]:5060 at 09:30:04.300257:
------------------------------------------------------------------------
INVITE sip:215 at tssec.ru SIP/2.0
Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-5520e68e
From: "Nikolai Gabelok" <sip:229 at tssec.ru>;tag=1e57eac0cc8bf959o0
To: "Elizarov Vladimir" <sip:215 at tssec.ru>
Call-ID: b4d6c80c-3143dc7d at 192.168.0.176
CSeq: 102 INVITE
Max-Forwards: 70
Proxy-Authorization: Digest
username="229",realm="tssec.ru",nonce="13679dc0-7abc-11df-97d3-6f7c82b8b4b4",uri="sip:215 at tssec.ru",algorithm=MD5,response="78382843426af5a5fb18bc30de5953fb",qop=auth,nc=00000001,cnonce="4faa6b95"
Contact: "Nikolai Gabelok" <sip:229 at 192.168.0.176:5060>
Expires: 240
User-Agent: Linksys/SPA921-5.1.8
Content-Length: 401
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces
Content-Type: application/sdp
v=0
o=- 31175322 31175322 IN IP4 192.168.0.176
s=-
c=IN IP4 192.168.0.176
t=0 0
m=audio 16472 RTP/AVP 8 0 2 4 18 96 97 98 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
------------------------------------------------------------------------
send 321 bytes to udp/[192.168.0.176]:5060 at 09:30:04.300257:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-5520e68e
From: "Nikolai Gabelok" <sip:229 at tssec.ru>;tag=1e57eac0cc8bf959o0
To: "Elizarov Vladimir" <sip:215 at tssec.ru>
Call-ID: b4d6c80c-3143dc7d at 192.168.0.176
CSeq: 102 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
Content-Length: 0
------------------------------------------------------------------------
2010-06-18 13:28:29.461276 [DEBUG] sofia.c:5949 IP 192.168.0.176
Rejected by acl "domains". Falling back to Digest auth.
2010-06-18 13:28:29.465278 [NOTICE] switch_channel.c:772 New Channel
sofia/internal/229 at tssec.ru [1371631e-7abc-11df-97d4-6f7c82b8b4b4]
2010-06-18 13:28:29.465278 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/229 at tssec.ru) Running State Change CS_NEW
2010-06-18 13:28:29.465278 [DEBUG] switch_core_state_machine.c:320
(sofia/internal/229 at tssec.ru) State NEW
2010-06-18 13:28:29.469280 [DEBUG] sofia.c:4281 Channel
sofia/internal/229 at tssec.ru entering state [received][100]
2010-06-18 13:28:29.469280 [DEBUG] sofia.c:4292 Remote SDP:
v=0
o=- 31175322 31175322 IN IP4 192.168.0.176
s=-
c=IN IP4 192.168.0.176
t=0 0
m=audio 16472 RTP/AVP 8 0 2 4 18 96 97 98 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
2010-06-18 13:28:29.469280 [DEBUG] sofia_glue.c:3879 Audio Codec
Compare [PCMA:8:8000:20]/[PCMU:0:8000:20]
2010-06-18 13:28:29.469280 [DEBUG] sofia_glue.c:3879 Audio Codec
Compare [PCMA:8:8000:20]/[PCMA:8:8000:20]
2010-06-18 13:28:29.469280 [DEBUG] sofia_glue.c:2464 Set Codec
sofia/internal/229 at tssec.ru PCMA/8000 20 ms 160 samples
2010-06-18 13:28:29.469280 [DEBUG] sofia_glue.c:3818 Set 2833 dtmf
send/recv payload to 101
2010-06-18 13:28:29.469280 [DEBUG] sofia.c:4431
(sofia/internal/229 at tssec.ru) State Change CS_NEW -> CS_INIT
2010-06-18 13:28:29.469280 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/229 at tssec.ru [BREAK]
2010-06-18 13:28:29.469280 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/229 at tssec.ru) Running State Change CS_INIT
2010-06-18 13:28:29.469280 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/229 at tssec.ru) State INIT
2010-06-18 13:28:29.469280 [DEBUG] mod_sofia.c:83
sofia/internal/229 at tssec.ru SOFIA INIT
2010-06-18 13:28:29.469280 [DEBUG] mod_sofia.c:117
(sofia/internal/229 at tssec.ru) State Change CS_INIT -> CS_ROUTING
2010-06-18 13:28:29.469280 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/229 at tssec.ru [BREAK]
2010-06-18 13:28:29.469280 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/229 at tssec.ru) State INIT going to sleep
2010-06-18 13:28:29.469280 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/229 at tssec.ru) Running State Change CS_ROUTING
2010-06-18 13:28:29.469280 [DEBUG] switch_channel.c:1470
(sofia/internal/229 at tssec.ru) Callstate Change DOWN -> RINGING
2010-06-18 13:28:29.469280 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/229 at tssec.ru) State ROUTING
2010-06-18 13:28:29.469280 [DEBUG] switch_channel.c:1329
(sofia/internal/229 at tssec.ru) Callstate Change RINGING -> ACTIVE
2010-06-18 13:28:29.469280 [DEBUG] mod_sofia.c:140
sofia/internal/229 at tssec.ru SOFIA ROUTING
2010-06-18 13:28:29.469280 [DEBUG] switch_core_state_machine.c:77
sofia/internal/229 at tssec.ru Standard ROUTING
2010-06-18 13:28:29.469280 [INFO] mod_dialplan_xml.c:331 Processing
Nikolai Gabelok->215 in context default
Dialplan: sofia/internal/229 at tssec.ru parsing [default->unloop] continue=false
Dialplan: sofia/internal/229 at tssec.ru Regex (PASS) [unloop]
${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/229 at tssec.ru Regex (FAIL) [unloop]
${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/229 at tssec.ru parsing [default->time of day
routing] continue=true
Dialplan: sofia/internal/229 at tssec.ru Date/Time Match (PASS) [time of
day routing] break=on-false
Dialplan: sofia/internal/229 at tssec.ru Action set(status=open)
Dialplan: sofia/internal/229 at tssec.ru Date/Time Match (FAIL) [time of
day routing] break=on-false
Dialplan: sofia/internal/229 at tssec.ru parsing [default->IVR] continue=false
Dialplan: sofia/internal/229 at tssec.ru Regex (FAIL) [IVR]
destination_number(215) =~ /^(ivr|5000)$/ break=on-false
Dialplan: sofia/internal/229 at tssec.ru parsing [default->delay_echo]
continue=false
Dialplan: sofia/internal/229 at tssec.ru Regex (FAIL) [delay_echo]
destination_number(215) =~ /^echo123$|^123$/ break=on-false
Dialplan: sofia/internal/229 at tssec.ru parsing
[default->delay_echo_next] continue=false
Dialplan: sofia/internal/229 at tssec.ru Regex (FAIL) [delay_echo_next]
destination_number(215) =~ /after_echo/ break=on-false
Dialplan: sofia/internal/229 at tssec.ru parsing
[default->global-intercept] continue=false
Dialplan: sofia/internal/229 at tssec.ru Regex (FAIL) [global-intercept]
destination_number(215) =~ /^\*\*$/ break=on-false
Dialplan: sofia/internal/229 at tssec.ru parsing
[default->group-intercept] continue=false
Dialplan: sofia/internal/229 at tssec.ru Regex (FAIL) [group-intercept]
destination_number(215) =~ /^\*$/ break=on-false
Dialplan: sofia/internal/229 at tssec.ru parsing
[default->extension-intercept] continue=false
Dialplan: sofia/internal/229 at tssec.ru Regex (FAIL)
[extension-intercept] destination_number(215) =~ /^\*(\d+)$/
break=on-false
Dialplan: sofia/internal/229 at tssec.ru parsing [default->sales] continue=false
Dialplan: sofia/internal/229 at tssec.ru Regex (FAIL) [sales]
destination_number(215) =~ /^sales$/ break=on-false
Dialplan: sofia/internal/229 at tssec.ru parsing [default->integrations]
continue=false
Dialplan: sofia/internal/229 at tssec.ru Regex (FAIL) [integrations]
destination_number(215) =~ /^integrations$/ break=on-false
Dialplan: sofia/internal/229 at tssec.ru parsing [default->operators]
continue=false
Dialplan: sofia/internal/229 at tssec.ru Regex (FAIL) [operators]
destination_number(215) =~ /^operators$/ break=on-false
Dialplan: sofia/internal/229 at tssec.ru parsing
[default->Local_Extension] continue=false
Dialplan: sofia/internal/229 at tssec.ru Regex (PASS) [Local_Extension]
destination_number(215) =~ /^([1-2][0-2][0-9])$/ break=on-false
Dialplan: sofia/internal/229 at tssec.ru Action set(dialed_extension=215)
Dialplan: sofia/internal/229 at tssec.ru Action export(dialed_extension=215)
Dialplan: sofia/internal/229 at tssec.ru Action export(RECORD_STEREO=true)
Dialplan: sofia/internal/229 at tssec.ru Action bind_meta_app(1 b s
execute_extension::dx XML features)
Dialplan: sofia/internal/229 at tssec.ru Action bind_meta_app(2 a s
record_session::/var/lib/freeswitch/recordings/${caller_id_number}.${destination_number}.${strftime(%Y-%m-%d-%H-%M)}.wav)
Dialplan: sofia/internal/229 at tssec.ru Action
record_session(/var/lib/freeswitch/recordings/${caller_id_number}.${destination_number}.${strftime(%Y-%m-%d-%H-%M)}.wav)
Dialplan: sofia/internal/229 at tssec.ru Action
hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
Dialplan: sofia/internal/229 at tssec.ru Action
hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/internal/229 at tssec.ru Action
set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
var callgroup)})
Dialplan: sofia/internal/229 at tssec.ru Action
hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/229 at tssec.ru Regex (FAIL) [Local_Extension]
destination_number(215) =~ /^100$/ break=on-true
Dialplan: sofia/internal/229 at tssec.ru Regex (FAIL) [Local_Extension]
destination_number(215) =~ /^229$/ break=on-false
Dialplan: sofia/internal/229 at tssec.ru ANTI-Action limit(tssec.ru
${destination_number} 1)
Dialplan: sofia/internal/229 at tssec.ru ANTI-Action
set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/229 at tssec.ru ANTI-Action
set(ringback=%(800,3200,425,0))
Dialplan: sofia/internal/229 at tssec.ru ANTI-Action set(call_timeout=15)
Dialplan: sofia/internal/229 at tssec.ru ANTI-Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/229 at tssec.ru ANTI-Action set(continue_on_fail=true)
Dialplan: sofia/internal/229 at tssec.ru ANTI-Action
bridge({ignore_early_media=true}${sofia_contact(internal/${dialed_extension}@tssec.ru)})
Dialplan: sofia/internal/229 at tssec.ru ANTI-Action
transfer(not_answer-${dialed_extension} XML default)
2010-06-18 13:28:29.473282 [DEBUG] switch_core_state_machine.c:119
(sofia/internal/229 at tssec.ru) State Change CS_ROUTING -> CS_EXECUTE
2010-06-18 13:28:29.473282 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/229 at tssec.ru [BREAK]
2010-06-18 13:28:29.473282 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/229 at tssec.ru) State ROUTING going to sleep
2010-06-18 13:28:29.473282 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/229 at tssec.ru) Running State Change CS_EXECUTE
2010-06-18 13:28:29.473282 [DEBUG] switch_core_state_machine.c:348
(sofia/internal/229 at tssec.ru) State EXECUTE
2010-06-18 13:28:29.473282 [DEBUG] mod_sofia.c:233
sofia/internal/229 at tssec.ru SOFIA EXECUTE
2010-06-18 13:28:29.473282 [DEBUG] switch_core_state_machine.c:157
sofia/internal/229 at tssec.ru Standard EXECUTE
EXECUTE sofia/internal/229 at tssec.ru set(status=open)
2010-06-18 13:28:29.473282 [DEBUG] mod_dptools.c:834
sofia/internal/229 at tssec.ru SET [status]=[open]
EXECUTE sofia/internal/229 at tssec.ru set(dialed_extension=215)
2010-06-18 13:28:29.473282 [DEBUG] mod_dptools.c:834
sofia/internal/229 at tssec.ru SET [dialed_extension]=[215]
EXECUTE sofia/internal/229 at tssec.ru export(dialed_extension=215)
2010-06-18 13:28:29.473282 [DEBUG] mod_dptools.c:918 EXPORT
[dialed_extension]=[215]
EXECUTE sofia/internal/229 at tssec.ru export(RECORD_STEREO=true)
2010-06-18 13:28:29.473282 [DEBUG] mod_dptools.c:918 EXPORT
[RECORD_STEREO]=[true]
EXECUTE sofia/internal/229 at tssec.ru bind_meta_app(1 b s
execute_extension::dx XML features)
2010-06-18 13:28:29.473282 [INFO] switch_ivr_async.c:2429 Bound B-Leg:
1 execute_extension::dx XML features
EXECUTE sofia/internal/229 at tssec.ru bind_meta_app(2 a s
record_session::/var/lib/freeswitch/recordings/229.215.2010-06-18-13-28.wav)
2010-06-18 13:28:29.473282 [INFO] switch_ivr_async.c:2422 Bound A-Leg:
2 record_session::/var/lib/freeswitch/recordings/229.215.2010-06-18-13-28.wav
2010-06-18 13:28:29.473282 [DEBUG] switch_core_session.c:1763
Application record_session Requires media! pre_answering channel
sofia/internal/229 at tssec.ru
2010-06-18 13:28:29.481286 [INFO] switch_core_session.c:1765 Sending early media
2010-06-18 13:28:29.481286 [DEBUG] sofia_glue.c:2704 AUDIO RTP
[sofia/internal/229 at tssec.ru] 192.168.50.11 port 24616 ->
192.168.0.176 port 16472 codec: 8 ms: 20
2010-06-18 13:28:29.481286 [DEBUG] switch_rtp.c:1373 Starting timer
[soft] 160 bytes per 20ms
2010-06-18 13:28:29.481286 [INFO] sofia_presence.c:663 IN
START_PRESENCE_SQL (internal)
2010-06-18 13:28:29.481286 [ERR] sofia_presence.c:672 DUMP PRESENCE SQL:
select sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'CS_ROUTING','unknown','tssec.ru',sip_presence.status,sip_presence.rpid
from sip_subscriptions left join sip_presence on
(sip_subscriptions.sub_to_user=sip_presence.sip_user and
sip_subscriptions.sub_to_host=sip_presence.sip_host and
sip_subscriptions.profile_name=sip_presence.profile_name) where
sip_subscriptions.expires > -1 and (event='presence' or
event='dialog') and sub_to_user='229' and (sub_to_host='tssec.ru' or
presence_hosts like '%tssec.ru%') and (sip_subscriptions.profile_name
= 'internal' or sip_subscriptions.presence_hosts !=
sip_subscriptions.sub_to_host)
EVENT DUMP:
Event-Name: [PRESENCE_IN]
Core-UUID: [9341fc9e-7a4d-11df-92e6-6f7c82b8b4b4]
FreeSWITCH-Hostname: [sip1.lan.tssec.ru]
FreeSWITCH-IPv4: [192.168.50.11]
FreeSWITCH-IPv6: [::1]
Event-Date-Local: [2010-06-18 13:28:29]
Event-Date-GMT: [Fri, 18 Jun 2010 09:28:29 GMT]
Event-Date-Timestamp: [1276853309469280]
Event-Calling-File: [switch_channel.c]
Event-Calling-Function: [switch_channel_presence]
Event-Calling-Line-Number: [575]
Channel-State: [CS_ROUTING]
Channel-Call-State: [DOWN]
Channel-State-Number: [2]
Channel-Name: [sofia/internal/229 at tssec.ru]
Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Channel-Presence-ID: [229 at tssec.ru]
Answer-State: [ringing]
Channel-Read-Codec-Name: [PCMA]
Channel-Read-Codec-Rate: [8000]
Channel-Write-Codec-Name: [PCMA]
Channel-Write-Codec-Rate: [8000]
Caller-Username: [229]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [Nikolai Gabelok]
Caller-Caller-ID-Number: [229]
Caller-Network-Addr: [192.168.0.176]
Caller-ANI: [229]
Caller-Destination-Number: [215]
Caller-Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4]
Caller-Source: [mod_sofia]
Caller-Context: [default]
Caller-Channel-Name: [sofia/internal/229 at tssec.ru]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1276853309465278]
Caller-Channel-Created-Time: [1276853309465278]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Progress-Time: [0]
Caller-Channel-Progress-Media-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
proto: [src/switch_channel.c]
login: [src/switch_channel.c]
from: [229 at tssec.ru]
rpid: [unknown]
status: [CS_ROUTING]
event_type: [presence]
alt_event_type: [dialog]
presence-call-direction: [inbound]
event_count: [0]
2010-06-18 13:28:29.481286 [NOTICE] sofia_presence.c:1126 SEND PRESENCE
To: 100 at tssec.ru
From: 229 at tssec.ru
Call-ID: e2bc3098-8a58ff8d at 192.168.0.220
Profile: internal [internal]
2010-06-18 13:28:29.481286 [WARNING] sofia_presence.c:1350 send payload:
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="0"
state="full" entity="sip:229 at tssec.ru">
<dialog id="1371631e-7abc-11df-97d4-6f7c82b8b4b4" direction="initiator">
<state>confirmed</state>
</dialog>
</dialog-info>
2010-06-18 13:28:29.481286 [INFO] sofia_presence.c:682 IN
END_PRESENCE_SQL (internal)
2010-06-18 13:28:29.481286 [WARNING] sofia_presence.c:593 tssec.ru is
an alias, skipping
2010-06-18 13:28:29.481286 [WARNING] sofia_presence.c:600 external is
passive, skipping
2010-06-18 13:28:29.481286 [INFO] sofia_presence.c:663 IN
START_PRESENCE_SQL (internal)
2010-06-18 13:28:29.481286 [ERR] sofia_presence.c:672 DUMP PRESENCE SQL:
select sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'CS_EXECUTE','unknown','tssec.ru',sip_presence.status,sip_presence.rpid
from sip_subscriptions left join sip_presence on
(sip_subscriptions.sub_to_user=sip_presence.sip_user and
sip_subscriptions.sub_to_host=sip_presence.sip_host and
sip_subscriptions.profile_name=sip_presence.profile_name) where
sip_subscriptions.expires > -1 and (event='presence' or
event='dialog') and sub_to_user='229' and (sub_to_host='tssec.ru' or
presence_hosts like '%tssec.ru%') and (sip_subscriptions.profile_name
= 'internal' or sip_subscriptions.presence_hosts !=
sip_subscriptions.sub_to_host)
EVENT DUMP:
Event-Name: [PRESENCE_IN]
Core-UUID: [9341fc9e-7a4d-11df-92e6-6f7c82b8b4b4]
FreeSWITCH-Hostname: [sip1.lan.tssec.ru]
FreeSWITCH-IPv4: [192.168.50.11]
FreeSWITCH-IPv6: [::1]
Event-Date-Local: [2010-06-18 13:28:29]
Event-Date-GMT: [Fri, 18 Jun 2010 09:28:29 GMT]
Event-Date-Timestamp: [1276853309473282]
Event-Calling-File: [switch_channel.c]
Event-Calling-Function: [switch_channel_presence]
Event-Calling-Line-Number: [575]
Channel-State: [CS_EXECUTE]
Channel-Call-State: [ACTIVE]
Channel-State-Number: [4]
Channel-Name: [sofia/internal/229 at tssec.ru]
Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Channel-Presence-ID: [229 at tssec.ru]
Answer-State: [ringing]
Channel-Read-Codec-Name: [PCMA]
Channel-Read-Codec-Rate: [8000]
Channel-Write-Codec-Name: [PCMA]
Channel-Write-Codec-Rate: [8000]
Caller-Username: [229]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [Nikolai Gabelok]
Caller-Caller-ID-Number: [229]
Caller-Network-Addr: [192.168.0.176]
Caller-ANI: [229]
Caller-Destination-Number: [215]
Caller-Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4]
Caller-Source: [mod_sofia]
Caller-Context: [default]
Caller-Channel-Name: [sofia/internal/229 at tssec.ru]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1276853309465278]
Caller-Channel-Created-Time: [1276853309465278]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Progress-Time: [0]
Caller-Channel-Progress-Media-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
proto: [src/switch_channel.c]
login: [src/switch_channel.c]
from: [229 at tssec.ru]
rpid: [unknown]
status: [CS_EXECUTE]
event_type: [presence]
alt_event_type: [dialog]
presence-call-direction: [inbound]
event_count: [1]
send 1043 bytes to udp/[192.168.0.220]:5060 at 09:30:04.324270:
------------------------------------------------------------------------
NOTIFY sip:100 at 192.168.0.220:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.50.11;rport;branch=z9hG4bK4emrN6m7HX3SS
Max-Forwards: 70
From: <sip:229 at tssec.ru>;tag=Be64rve6FSU1D
To: <sip:100 at tssec.ru>;tag=beeaf51cf0d364d9
Call-ID: e2bc3098-8a58ff8d at 192.168.0.220
CSeq: 132308349 NOTIFY
Contact: <sip:229 at 192.168.50.11:5060>
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Event: dialog
Allow-Events: talk, hold, presence, dialog, line-seize, call-info,
sla, include-session-description, presence.winfo, message-summary,
refer
Subscription-State: active;expires=1164
Content-Type: application/dialog-info+xml
Content-Length: 253
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="0"
state="full" entity="sip:229 at tssec.ru">
<dialog id="1371631e-7abc-11df-97d4-6f7c82b8b4b4" direction="initiator">
<state>confirmed</state>
</dialog>
</dialog-info>
------------------------------------------------------------------------
2010-06-18 13:28:29.481286 [NOTICE] sofia_presence.c:1126 SEND PRESENCE
To: 100 at tssec.ru
From: 229 at tssec.ru
Call-ID: e2bc3098-8a58ff8d at 192.168.0.220
Profile: internal [internal]
2010-06-18 13:28:29.481286 [DEBUG] sofia_glue.c:2914 Set 2833 dtmf
send payload to 101
2010-06-18 13:28:29.481286 [DEBUG] sofia_glue.c:2919 Set 2833 dtmf
receive payload to 101
2010-06-18 13:28:29.481286 [DEBUG] mod_sofia.c:2101 Ring SDP:
v=0
o=FreeSWITCH 1276828693 1276828694 IN IP4 192.168.50.11
s=FreeSWITCH
c=IN IP4 192.168.50.11
t=0 0
m=audio 24616 RTP/AVP 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
2010-06-18 13:28:29.481286 [NOTICE] mod_sofia.c:2104 Pre-Answer
sofia/internal/229 at tssec.ru!
2010-06-18 13:28:29.481286 [INFO] sofia_presence.c:682 IN
END_PRESENCE_SQL (internal)
2010-06-18 13:28:29.481286 [WARNING] sofia_presence.c:593 tssec.ru is
an alias, skipping
2010-06-18 13:28:29.481286 [WARNING] sofia_presence.c:600 external is
passive, skipping
2010-06-18 13:28:29.481286 [DEBUG] switch_channel.c:2343
(sofia/internal/229 at tssec.ru) Callstate Change ACTIVE -> EARLY
2010-06-18 13:28:29.481286 [DEBUG] switch_core_session.c:643 Send
signal sofia/internal/229 at tssec.ru [BREAK]
EXECUTE sofia/internal/229 at tssec.ru
record_session(/var/lib/freeswitch/recordings/229.215.2010-06-18-13-28.wav)
2010-06-18 13:28:29.481286 [DEBUG] switch_core_media_bug.c:365
Attaching BUG to sofia/internal/229 at tssec.ru
EXECUTE sofia/internal/229 at tssec.ru hash(insert/tssec.ru-call_return/215/229)
send 1115 bytes to udp/[192.168.0.176]:5060 at 09:30:04.324270:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-5520e68e
From: "Nikolai Gabelok" <sip:229 at tssec.ru>;tag=1e57eac0cc8bf959o0
To: "Elizarov Vladimir" <sip:215 at tssec.ru>;tag=D0rpvjgDaB86m
Call-ID: b4d6c80c-3143dc7d at 192.168.0.176
CSeq: 102 INVITE
Contact: <sip:215 at 192.168.50.11:5060;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Allow-Events: talk, hold, presence, dialog, line-seize, call-info,
sla, include-session-description, presence.winfo, message-summary,
refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 249
Remote-Party-ID: "215" <sip:215@(null)>;party=calling;privacy=off;screen=no
v=0
o=FreeSWITCH 1276828693 1276828694 IN IP4 192.168.50.11
s=FreeSWITCH
c=IN IP4 192.168.50.11
t=0 0
m=audio 24616 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
------------------------------------------------------------------------
2010-06-18 13:28:29.481286 [DEBUG] sofia.c:4276 Channel
sofia/internal/229 at tssec.ru skipping state [early][183]
EXECUTE sofia/internal/229 at tssec.ru
hash(insert/tssec.ru-last_dial_ext/215/1371631e-7abc-11df-97d4-6f7c82b8b4b4)
EXECUTE sofia/internal/229 at tssec.ru set(called_party_callgroup=1)
2010-06-18 13:28:29.481286 [DEBUG] mod_dptools.c:834
sofia/internal/229 at tssec.ru SET [called_party_callgroup]=[1]
EXECUTE sofia/internal/229 at tssec.ru
hash(insert/tssec.ru-last_dial/1/1371631e-7abc-11df-97d4-6f7c82b8b4b4)
EXECUTE sofia/internal/229 at tssec.ru limit(tssec.ru 215 1)
2010-06-18 13:28:29.481286 [INFO] mod_limit.c:729 Usage for
tssec.ru_215 is now 1/1
EXECUTE sofia/internal/229 at tssec.ru set(transfer_ringback=local_stream://moh)
2010-06-18 13:28:29.493293 [DEBUG] mod_dptools.c:834
sofia/internal/229 at tssec.ru SET
[transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/229 at tssec.ru set(ringback=%(800,3200,425,0))
2010-06-18 13:28:29.493293 [DEBUG] mod_dptools.c:834
sofia/internal/229 at tssec.ru SET [ringback]=[%(800,3200,425,0)]
EXECUTE sofia/internal/229 at tssec.ru set(call_timeout=15)
2010-06-18 13:28:29.493293 [DEBUG] mod_dptools.c:834
sofia/internal/229 at tssec.ru SET [call_timeout]=[15]
EXECUTE sofia/internal/229 at tssec.ru set(hangup_after_bridge=true)
2010-06-18 13:28:29.493293 [DEBUG] mod_dptools.c:834
sofia/internal/229 at tssec.ru SET [hangup_after_bridge]=[true]
EXECUTE sofia/internal/229 at tssec.ru set(continue_on_fail=true)
2010-06-18 13:28:29.493293 [DEBUG] mod_dptools.c:834
sofia/internal/229 at tssec.ru SET [continue_on_fail]=[true]
EXECUTE sofia/internal/229 at tssec.ru
bridge({ignore_early_media=true}sofia/internal/sip:215 at 10.8.6.6:5080,sofia/internal/sip:215 at 192.168.1.118:5060)
2010-06-18 13:28:29.493293 [DEBUG] switch_ivr_originate.c:1944
variable string 0 = [ignore_early_media=true]
2010-06-18 13:28:29.493293 [NOTICE] switch_channel.c:772 New Channel
sofia/internal/sip:215 at 10.8.6.6:5080
[1375a974-7abc-11df-97d5-6f7c82b8b4b4]
2010-06-18 13:28:29.493293 [DEBUG] mod_sofia.c:3817
(sofia/internal/sip:215 at 10.8.6.6:5080) State Change CS_NEW -> CS_INIT
2010-06-18 13:28:29.493293 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/sip:215 at 10.8.6.6:5080 [BREAK]
2010-06-18 13:28:29.493293 [NOTICE] switch_channel.c:772 New Channel
sofia/internal/sip:215 at 192.168.1.118:5060
[1375a975-7abc-11df-97d6-6f7c82b8b4b4]
2010-06-18 13:28:29.493293 [DEBUG] mod_sofia.c:3817
(sofia/internal/sip:215 at 192.168.1.118:5060) State Change CS_NEW ->
CS_INIT
2010-06-18 13:28:29.493293 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/sip:215 at 192.168.1.118:5060 [BREAK]
2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:215 at 192.168.1.118:5060) Running State Change
CS_INIT
2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:215 at 10.8.6.6:5080) Running State Change CS_INIT
2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/sip:215 at 10.8.6.6:5080) State INIT
2010-06-18 13:28:29.493293 [DEBUG] mod_sofia.c:83
sofia/internal/sip:215 at 10.8.6.6:5080 SOFIA INIT
2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/sip:215 at 192.168.1.118:5060) State INIT
2010-06-18 13:28:29.493293 [DEBUG] mod_sofia.c:83
sofia/internal/sip:215 at 192.168.1.118:5060 SOFIA INIT
send 1185 bytes to udp/[10.8.6.6]:5080 at 09:30:04.332274:
------------------------------------------------------------------------
INVITE sip:215 at 10.8.6.6:5080 SIP/2.0
Via: SIP/2.0/UDP 192.168.50.11;rport;branch=z9hG4bK5QDHQ15aF6ScN
Max-Forwards: 69
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=e9HFyD1g7KySg
To: <sip:215 at 10.8.6.6:5080>
Call-ID: ead3e978-f55e-122d-a480-00163efcbed2
CSeq: 132308366 INVITE
Contact: <sip:mod_sofia at 192.168.50.11:5060>
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Allow-Events: talk, hold, presence, dialog, line-seize, call-info,
sla, include-session-description, presence.winfo, message-summary,
refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 293
X-FS-Support: update_display
Remote-Party-ID: "Nikolai Gabelok"
<sip:229 at 192.168.50.11>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1276826303 1276826304 IN IP4 192.168.50.11
s=FreeSWITCH
c=IN IP4 192.168.50.11
t=0 0
m=audio 27006 RTP/AVP 8 0 3 101 13
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
------------------------------------------------------------------------
2010-06-18 13:28:29.493293 [DEBUG] mod_sofia.c:117
(sofia/internal/sip:215 at 10.8.6.6:5080) State Change CS_INIT ->
CS_ROUTING
2010-06-18 13:28:29.493293 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/sip:215 at 10.8.6.6:5080 [BREAK]
2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/sip:215 at 10.8.6.6:5080) State INIT going to sleep
2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:215 at 10.8.6.6:5080) Running State Change CS_ROUTING
2010-06-18 13:28:29.493293 [DEBUG] switch_channel.c:1470
(sofia/internal/sip:215 at 10.8.6.6:5080) Callstate Change DOWN ->
RINGING
2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/sip:215 at 10.8.6.6:5080) State ROUTING
2010-06-18 13:28:29.493293 [DEBUG] switch_channel.c:1329
(sofia/internal/sip:215 at 10.8.6.6:5080) Callstate Change RINGING ->
ACTIVE
2010-06-18 13:28:29.493293 [DEBUG] mod_sofia.c:140
sofia/internal/sip:215 at 10.8.6.6:5080 SOFIA ROUTING
2010-06-18 13:28:29.493293 [DEBUG] switch_ivr_originate.c:64
(sofia/internal/sip:215 at 10.8.6.6:5080) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2010-06-18 13:28:29.493293 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/sip:215 at 10.8.6.6:5080 [BREAK]
2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/sip:215 at 10.8.6.6:5080) State ROUTING going to sleep
2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:215 at 10.8.6.6:5080) Running State Change
CS_CONSUME_MEDIA
2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/sip:215 at 10.8.6.6:5080) State CONSUME_MEDIA
2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/sip:215 at 10.8.6.6:5080) State CONSUME_MEDIA going to
sleep
recv 285 bytes from udp/[192.168.0.220]:5060 at 09:30:04.336276:
------------------------------------------------------------------------
SIP/2.0 200 OK
To: <sip:100 at tssec.ru>;tag=beeaf51cf0d364d9
From: <sip:229 at tssec.ru>;tag=Be64rve6FSU1D
Call-ID: e2bc3098-8a58ff8d at 192.168.0.220
CSeq: 132308349 NOTIFY
Via: SIP/2.0/UDP 192.168.50.11;branch=z9hG4bK4emrN6m7HX3SS
Server: Linksys/SPA962-6.1.3(a)
Content-Length: 0
------------------------------------------------------------------------
2010-06-18 13:28:29.493293 [DEBUG] sofia.c:4281 Channel
sofia/internal/sip:215 at 10.8.6.6:5080 entering state [calling][0]
2010-06-18 13:28:29.497295 [DEBUG] mod_sofia.c:117
(sofia/internal/sip:215 at 192.168.1.118:5060) State Change CS_INIT ->
CS_ROUTING
2010-06-18 13:28:29.497295 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/sip:215 at 192.168.1.118:5060 [BREAK]
2010-06-18 13:28:29.497295 [DEBUG] switch_core_state_machine.c:338
(sofia/internal/sip:215 at 192.168.1.118:5060) State INIT going to sleep
2010-06-18 13:28:29.497295 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:215 at 192.168.1.118:5060) Running State Change
CS_ROUTING
2010-06-18 13:28:29.497295 [DEBUG] switch_channel.c:1470
(sofia/internal/sip:215 at 192.168.1.118:5060) Callstate Change DOWN ->
RINGING
send 1195 bytes to udp/[192.168.1.118]:5060 at 09:30:04.336276:
------------------------------------------------------------------------
INVITE sip:215 at 192.168.1.118:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.50.11;rport;branch=z9hG4bK6069rvpecFgZg
Max-Forwards: 69
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=FjB8Z8Hm4vmcc
To: <sip:215 at 192.168.1.118:5060>
Call-ID: ead485ce-f55e-122d-a480-00163efcbed2
CSeq: 132308366 INVITE
Contact: <sip:mod_sofia at 192.168.50.11:5060>
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Allow-Events: talk, hold, presence, dialog, line-seize, call-info,
sla, include-session-description, presence.winfo, message-summary,
refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 293
X-FS-Support: update_display
Remote-Party-ID: "Nikolai Gabelok"
<sip:229 at 192.168.50.11>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1276821601 1276821602 IN IP4 192.168.50.11
s=FreeSWITCH
c=IN IP4 192.168.50.11
t=0 0
m=audio 31708 RTP/AVP 8 0 3 101 13
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
------------------------------------------------------------------------
2010-06-18 13:28:29.497295 [DEBUG] sofia.c:4281 Channel
sofia/internal/sip:215 at 192.168.1.118:5060 entering state [calling][0]
2010-06-18 13:28:29.501297 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/sip:215 at 192.168.1.118:5060) State ROUTING
2010-06-18 13:28:29.501297 [DEBUG] switch_channel.c:1329
(sofia/internal/sip:215 at 192.168.1.118:5060) Callstate Change RINGING
-> ACTIVE
2010-06-18 13:28:29.501297 [DEBUG] mod_sofia.c:140
sofia/internal/sip:215 at 192.168.1.118:5060 SOFIA ROUTING
2010-06-18 13:28:29.501297 [DEBUG] switch_ivr_originate.c:64
(sofia/internal/sip:215 at 192.168.1.118:5060) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2010-06-18 13:28:29.501297 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/sip:215 at 192.168.1.118:5060 [BREAK]
2010-06-18 13:28:29.501297 [DEBUG] switch_core_state_machine.c:341
(sofia/internal/sip:215 at 192.168.1.118:5060) State ROUTING going to
sleep
2010-06-18 13:28:29.501297 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:215 at 192.168.1.118:5060) Running State Change
CS_CONSUME_MEDIA
2010-06-18 13:28:29.501297 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/sip:215 at 192.168.1.118:5060) State CONSUME_MEDIA
2010-06-18 13:28:29.501297 [DEBUG] switch_core_state_machine.c:360
(sofia/internal/sip:215 at 192.168.1.118:5060) State CONSUME_MEDIA going
to sleep
recv 392 bytes from udp/[192.168.1.118]:5060 at 09:30:04.348283:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.50.11;rport=5060;branch=z9hG4bK6069rvpecFgZg
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=FjB8Z8Hm4vmcc
To: <sip:215 at 192.168.1.118:5060>
Call-ID: ead485ce-f55e-122d-a480-00163efcbed2
CSeq: 132308366 INVITE
Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE
User-Agent: SIPPER for PhonerLite
Content-Length: 0
------------------------------------------------------------------------
recv 469 bytes from udp/[192.168.1.118]:5060 at 09:30:04.352285:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.50.11;rport=5060;branch=z9hG4bK6069rvpecFgZg
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=FjB8Z8Hm4vmcc
To: <sip:215 at 192.168.1.118:5060>;tag=800c08bf2979df11bda80013d4bfa980
Call-ID: ead485ce-f55e-122d-a480-00163efcbed2
CSeq: 132308366 INVITE
Contact: <sip:215 at 192.168.1.118:5060>
Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE
User-Agent: SIPPER for PhonerLite
Content-Length: 0
------------------------------------------------------------------------
2010-06-18 13:28:29.509302 [INFO] sofia.c:662
sofia/internal/sip:215 at 192.168.1.118:5060 Update Callee ID to "215"
<215>
2010-06-18 13:28:29.521308 [DEBUG] sofia.c:4281 Channel
sofia/internal/sip:215 at 192.168.1.118:5060 entering state
[proceeding][180]
2010-06-18 13:28:29.521308 [NOTICE] sofia.c:4351 Ring-Ready
sofia/internal/sip:215 at 192.168.1.118:5060!
2010-06-18 13:28:29.541319 [DEBUG] switch_rtp.c:2476 Correct ip/port confirmed.
2010-06-18 13:28:29.561329 [DEBUG] switch_ivr_originate.c:1125 Raw
Codec Activation Success L16 at 8000hz 1 channel 20ms
2010-06-18 13:28:29.561329 [DEBUG] switch_core_codec.c:122
sofia/internal/229 at tssec.ru Push codec L16:10
2010-06-18 13:28:29.561329 [DEBUG] switch_ivr_originate.c:1190 Play
Ringback Tone [%(800,3200,425,0)]
recv 325 bytes from udp/[10.8.6.6]:5080 at 09:30:04.440332:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP
192.168.50.11;received=192.168.50.11;rport=5060;branch=z9hG4bK5QDHQ15aF6ScN
To: <sip:215 at 10.8.6.6:5080>
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=e9HFyD1g7KySg
Call-ID: ead3e978-f55e-122d-a480-00163efcbed2
CSeq: 132308366 INVITE
Server: Twinkle/1.4.2
Content-Length: 0
------------------------------------------------------------------------
recv 370 bytes from udp/[10.8.6.6]:5080 at 09:30:04.440332:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP
192.168.50.11;received=192.168.50.11;rport=5060;branch=z9hG4bK5QDHQ15aF6ScN
To: <sip:215 at 10.8.6.6:5080>;tag=fyiai
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=e9HFyD1g7KySg
Call-ID: ead3e978-f55e-122d-a480-00163efcbed2
CSeq: 132308366 INVITE
Contact: <sip:215 at 10.8.6.6:5080>
Server: Twinkle/1.4.2
Content-Length: 0
------------------------------------------------------------------------
2010-06-18 13:28:29.601351 [INFO] sofia.c:662
sofia/internal/sip:215 at 10.8.6.6:5080 Update Callee ID to "215" <215>
2010-06-18 13:28:29.605353 [DEBUG] sofia.c:4281 Channel
sofia/internal/sip:215 at 10.8.6.6:5080 entering state [proceeding][180]
2010-06-18 13:28:29.605353 [NOTICE] sofia.c:4351 Ring-Ready
sofia/internal/sip:215 at 10.8.6.6:5080!
recv 709 bytes from udp/[10.8.6.6]:5080 at 09:30:06.501439:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP
192.168.50.11;received=192.168.50.11;rport=5060;branch=z9hG4bK5QDHQ15aF6ScN
To: <sip:215 at 10.8.6.6:5080>;tag=fyiai
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=e9HFyD1g7KySg
Call-ID: ead3e978-f55e-122d-a480-00163efcbed2
CSeq: 132308366 INVITE
Contact: <sip:215 at 10.8.6.6:5080>
Content-Type: application/sdp
Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,REFER,NOTIFY,SUBSCRIBE,INFO,MESSAGE
Server: Twinkle/1.4.2
Supported: replaces,norefersub
Content-Length: 199
v=0
o=twinkle 1275731453 434782481 IN IP4 10.8.6.6
s=-
c=IN IP4 10.8.6.6
t=0 0
m=audio 16535 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
------------------------------------------------------------------------
2010-06-18 13:28:31.670463 [DEBUG] sofia.c:4281 Channel
sofia/internal/sip:215 at 10.8.6.6:5080 entering state [completing][200]
2010-06-18 13:28:31.670463 [DEBUG] sofia.c:4292 Remote SDP:
v=0
o=twinkle 1275731453 434782481 IN IP4 10.8.6.6
s=-
c=IN IP4 10.8.6.6
t=0 0
m=audio 16535 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
send 359 bytes to udp/[10.8.6.6]:5080 at 09:30:06.509444:
------------------------------------------------------------------------
ACK sip:215 at 10.8.6.6:5080 SIP/2.0
Via: SIP/2.0/UDP 192.168.50.11;rport;branch=z9hG4bK79Z2tQ7H9Q6Hc
Max-Forwards: 70
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=e9HFyD1g7KySg
To: <sip:215 at 10.8.6.6:5080>;tag=fyiai
Call-ID: ead3e978-f55e-122d-a480-00163efcbed2
CSeq: 132308366 ACK
Contact: <sip:mod_sofia at 192.168.50.11:5060>
Content-Length: 0
------------------------------------------------------------------------
2010-06-18 13:28:31.670463 [DEBUG] sofia.c:4281 Channel
sofia/internal/sip:215 at 10.8.6.6:5080 entering state [ready][200]
2010-06-18 13:28:31.670463 [DEBUG] sofia_glue.c:3879 Audio Codec
Compare [PCMA:8:8000:20]/[PCMA:8:8000:20]
2010-06-18 13:28:31.670463 [DEBUG] sofia_glue.c:2464 Set Codec
sofia/internal/sip:215 at 10.8.6.6:5080 PCMA/8000 20 ms 160 samples
2010-06-18 13:28:31.670463 [DEBUG] sofia_glue.c:3812 Set 2833 dtmf
send payload to 101
2010-06-18 13:28:31.670463 [DEBUG] sofia_glue.c:2704 AUDIO RTP
[sofia/internal/sip:215 at 10.8.6.6:5080] 192.168.50.11 port 27006 ->
10.8.6.6 port 16535 codec: 8 ms: 20
2010-06-18 13:28:31.670463 [DEBUG] switch_rtp.c:1373 Starting timer
[soft] 160 bytes per 20ms
2010-06-18 13:28:31.670463 [DEBUG] sofia_glue.c:2914 Set 2833 dtmf
send payload to 101
2010-06-18 13:28:31.670463 [DEBUG] sofia_glue.c:2919 Set 2833 dtmf
receive payload to 101
2010-06-18 13:28:31.670463 [DEBUG] switch_channel.c:2497 Send signal
sofia/internal/229 at tssec.ru [BREAK]
2010-06-18 13:28:31.670463 [NOTICE] sofia.c:4831 Channel
[sofia/internal/sip:215 at 10.8.6.6:5080] has been answered
2010-06-18 13:28:31.682469 [DEBUG] switch_core_codec.c:146
sofia/internal/229 at tssec.ru Restore previous codec PCMA:8.
2010-06-18 13:28:31.682469 [DEBUG] switch_channel.c:2257
(sofia/internal/sip:215 at 192.168.1.118:5060) Callstate Change ACTIVE ->
HANGUP
2010-06-18 13:28:31.682469 [NOTICE] switch_ivr_originate.c:3192 Hangup
sofia/internal/sip:215 at 192.168.1.118:5060 [CS_CONSUME_MEDIA]
[LOSE_RACE]
2010-06-18 13:28:31.682469 [DEBUG] switch_channel.c:2273 Send signal
sofia/internal/sip:215 at 192.168.1.118:5060 [KILL]
2010-06-18 13:28:31.682469 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/sip:215 at 192.168.1.118:5060 [BREAK]
2010-06-18 13:28:31.682469 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:215 at 192.168.1.118:5060) Running State Change
CS_HANGUP
2010-06-18 13:28:31.682469 [DEBUG] switch_core_state_machine.c:500
(sofia/internal/sip:215 at 192.168.1.118:5060) State HANGUP
2010-06-18 13:28:31.682469 [DEBUG] mod_sofia.c:441 Channel
sofia/internal/sip:215 at 192.168.1.118:5060 hanging up, cause: LOSE_RACE
2010-06-18 13:28:31.690473 [DEBUG] mod_sofia.c:663 Local SDP
sofia/internal/229 at tssec.ru:
v=0
o=FreeSWITCH 1276828693 1276828695 IN IP4 192.168.50.11
s=FreeSWITCH
c=IN IP4 192.168.50.11
t=0 0
m=audio 24616 RTP/AVP 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
2010-06-18 13:28:31.690473 [DEBUG] switch_core_session.c:643 Send
signal sofia/internal/229 at tssec.ru [BREAK]
2010-06-18 13:28:31.690473 [DEBUG] switch_channel.c:2485
(sofia/internal/229 at tssec.ru) Callstate Change EARLY -> ACTIVE
2010-06-18 13:28:31.690473 [NOTICE] switch_ivr_originate.c:3216
Channel [sofia/internal/229 at tssec.ru] has been answered
2010-06-18 13:28:31.690473 [DEBUG] switch_ivr_originate.c:3261
Originate Resulted in Success: [sofia/internal/sip:215 at 10.8.6.6:5080]
2010-06-18 13:28:31.690473 [DEBUG] switch_core_session.c:643 Send
signal sofia/internal/sip:215 at 10.8.6.6:5080 [BREAK]
2010-06-18 13:28:31.690473 [DEBUG] switch_core_session.c:643 Send
signal sofia/internal/229 at tssec.ru [BREAK]
2010-06-18 13:28:31.690473 [DEBUG] switch_ivr_bridge.c:1182
(sofia/internal/sip:215 at 10.8.6.6:5080) State Change CS_CONSUME_MEDIA
-> CS_EXCHANGE_MEDIA
send 1076 bytes to udp/[192.168.0.176]:5060 at 09:30:06.529454:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-5520e68e
From: "Nikolai Gabelok" <sip:229 at tssec.ru>;tag=1e57eac0cc8bf959o0
To: "Elizarov Vladimir" <sip:215 at tssec.ru>;tag=D0rpvjgDaB86m
Call-ID: b4d6c80c-3143dc7d at 192.168.0.176
CSeq: 102 INVITE
Contact: <sip:215 at 192.168.50.11:5060;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Allow-Events: talk, hold, presence, dialog, line-seize, call-info,
sla, include-session-description, presence.winfo, message-summary,
refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 249
Remote-Party-ID: "215" <sip:215@(null)>;party=calling;privacy=off;screen=no
v=0
o=FreeSWITCH 1276828693 1276828694 IN IP4 192.168.50.11
s=FreeSWITCH
c=IN IP4 192.168.50.11
t=0 0
m=audio 24616 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
------------------------------------------------------------------------
2010-06-18 13:28:31.690473 [DEBUG] sofia.c:4281 Channel
sofia/internal/229 at tssec.ru entering state [completed][200]
2010-06-18 13:28:31.690473 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/sip:215 at 10.8.6.6:5080 [BREAK]
2010-06-18 13:28:31.690473 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:215 at 10.8.6.6:5080) Running State Change
CS_EXCHANGE_MEDIA
2010-06-18 13:28:31.690473 [DEBUG] switch_core_state_machine.c:351
(sofia/internal/sip:215 at 10.8.6.6:5080) State EXCHANGE_MEDIA
2010-06-18 13:28:31.690473 [DEBUG] mod_sofia.c:534 SOFIA EXCHANGE_MEDIA
2010-06-18 13:28:31.702480 [DEBUG] mod_sofia.c:494 Sending CANCEL to
sofia/internal/sip:215 at 192.168.1.118:5060
2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:46
sofia/internal/sip:215 at 192.168.1.118:5060 Standard HANGUP, cause:
LOSE_RACE
2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:500
(sofia/internal/sip:215 at 192.168.1.118:5060) State HANGUP going to
sleep
2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/sip:215 at 192.168.1.118:5060) State Change CS_HANGUP ->
CS_REPORTING
2010-06-18 13:28:31.702480 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/sip:215 at 192.168.1.118:5060 [BREAK]
2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:215 at 192.168.1.118:5060) Running State Change
CS_REPORTING
2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:591
(sofia/internal/sip:215 at 192.168.1.118:5060) State REPORTING
2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:53
sofia/internal/sip:215 at 192.168.1.118:5060 Standard REPORTING, cause:
LOSE_RACE
2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:591
(sofia/internal/sip:215 at 192.168.1.118:5060) State REPORTING going to
sleep
2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:327
(sofia/internal/sip:215 at 192.168.1.118:5060) State Change CS_REPORTING
-> CS_DESTROY
2010-06-18 13:28:31.702480 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/sip:215 at 192.168.1.118:5060 [BREAK]
2010-06-18 13:28:31.702480 [DEBUG] switch_core_session.c:1171 Session
116 (sofia/internal/sip:215 at 192.168.1.118:5060) Locked, Waiting on
external entities
2010-06-18 13:28:31.702480 [NOTICE] switch_core_session.c:1189 Session
116 (sofia/internal/sip:215 at 192.168.1.118:5060) Ended
2010-06-18 13:28:31.702480 [NOTICE] switch_core_session.c:1191 Close
Channel sofia/internal/sip:215 at 192.168.1.118:5060 [CS_DESTROY]
2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:427
(sofia/internal/sip:215 at 192.168.1.118:5060) Callstate Change HANGUP ->
DOWN
2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:430
(sofia/internal/sip:215 at 192.168.1.118:5060) Running State Change
CS_DESTROY
2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/sip:215 at 192.168.1.118:5060) State DESTROY
2010-06-18 13:28:31.702480 [DEBUG] mod_sofia.c:350
sofia/internal/sip:215 at 192.168.1.118:5060 SOFIA DESTROY
2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:60
sofia/internal/sip:215 at 192.168.1.118:5060 Standard DESTROY
2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/sip:215 at 192.168.1.118:5060) State DESTROY going to
sleep
send 375 bytes to udp/[192.168.1.118]:5060 at 09:30:06.541461:
------------------------------------------------------------------------
CANCEL sip:215 at 192.168.1.118:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.50.11;rport;branch=z9hG4bK6069rvpecFgZg
Max-Forwards: 69
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=FjB8Z8Hm4vmcc
To: <sip:215 at 192.168.1.118:5060>
Call-ID: ead485ce-f55e-122d-a480-00163efcbed2
CSeq: 132308366 CANCEL
Reason: SIP;cause=200;text="Call completed elsewhere"
Content-Length: 0
------------------------------------------------------------------------
recv 472 bytes from udp/[192.168.1.118]:5060 at 09:30:06.549465:
------------------------------------------------------------------------
SIP/2.0 200 cancelling
Via: SIP/2.0/UDP 192.168.50.11;rport=5060;branch=z9hG4bK6069rvpecFgZg
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=FjB8Z8Hm4vmcc
To: <sip:215 at 192.168.1.118:5060>;tag=800c08bf2979df11bda80013d4bfa980
Call-ID: ead485ce-f55e-122d-a480-00163efcbed2
CSeq: 132308366 CANCEL
Contact: <sip:215 at 192.168.1.118:5060>
Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE
User-Agent: SIPPER for PhonerLite
Content-Length: 0
------------------------------------------------------------------------
recv 479 bytes from udp/[192.168.1.118]:5060 at 09:30:06.549465:
------------------------------------------------------------------------
SIP/2.0 487 Request Cancelled
Via: SIP/2.0/UDP 192.168.50.11;rport=5060;branch=z9hG4bK6069rvpecFgZg
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=FjB8Z8Hm4vmcc
To: <sip:215 at 192.168.1.118:5060>;tag=800c08bf2979df11bda80013d4bfa980
Call-ID: ead485ce-f55e-122d-a480-00163efcbed2
CSeq: 132308366 INVITE
Contact: <sip:215 at 192.168.1.118:5060>
Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE
User-Agent: SIPPER for PhonerLite
Content-Length: 0
------------------------------------------------------------------------
send 351 bytes to udp/[192.168.1.118]:5060 at 09:30:06.549465:
------------------------------------------------------------------------
ACK sip:215 at 192.168.1.118:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.50.11;rport;branch=z9hG4bK6069rvpecFgZg
Max-Forwards: 69
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=FjB8Z8Hm4vmcc
To: <sip:215 at 192.168.1.118:5060>;tag=800c08bf2979df11bda80013d4bfa980
Call-ID: ead485ce-f55e-122d-a480-00163efcbed2
CSeq: 132308366 ACK
Content-Length: 0
------------------------------------------------------------------------
recv 657 bytes from udp/[192.168.0.176]:5060 at 09:30:06.561472:
------------------------------------------------------------------------
ACK sip:215 at 192.168.50.11:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-f67380cd
From: "Nikolai Gabelok" <sip:229 at tssec.ru>;tag=1e57eac0cc8bf959o0
To: "Elizarov Vladimir" <sip:215 at tssec.ru>;tag=D0rpvjgDaB86m
Call-ID: b4d6c80c-3143dc7d at 192.168.0.176
CSeq: 102 ACK
Max-Forwards: 70
Proxy-Authorization: Digest
username="229",realm="tssec.ru",nonce="13679dc0-7abc-11df-97d3-6f7c82b8b4b4",uri="sip:215 at tssec.ru",algorithm=MD5,response="78382843426af5a5fb18bc30de5953fb",qop=auth,nc=00000001,cnonce="4faa6b95"
Contact: "Nikolai Gabelok" <sip:229 at 192.168.0.176:5060>
User-Agent: Linksys/SPA921-5.1.8
Content-Length: 0
------------------------------------------------------------------------
2010-06-18 13:28:31.722491 [DEBUG] sofia.c:4281 Channel
sofia/internal/229 at tssec.ru entering state [ready][200]
2010-06-18 13:28:31.742501 [DEBUG] switch_core_session.c:704 Send
signal sofia/internal/sip:215 at 10.8.6.6:5080 [BREAK]
2010-06-18 13:28:31.742501 [DEBUG] switch_core_session.c:704 Send
signal sofia/internal/229 at tssec.ru [BREAK]
2010-06-18 13:28:31.782523 [INFO] sofia_presence.c:663 IN
START_PRESENCE_SQL (internal)
2010-06-18 13:28:31.782523 [ERR] sofia_presence.c:672 DUMP PRESENCE SQL:
select sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'answered','unknown','tssec.ru',sip_presence.status,sip_presence.rpid
from sip_subscriptions left join sip_presence on
(sip_subscriptions.sub_to_user=sip_presence.sip_user and
sip_subscriptions.sub_to_host=sip_presence.sip_host and
sip_subscriptions.profile_name=sip_presence.profile_name) where
sip_subscriptions.expires > -1 and (event='presence' or
event='dialog') and sub_to_user='229' and (sub_to_host='tssec.ru' or
presence_hosts like '%tssec.ru%') and (sip_subscriptions.profile_name
= 'internal' or sip_subscriptions.presence_hosts !=
sip_subscriptions.sub_to_host)
EVENT DUMP:
Event-Name: [PRESENCE_IN]
Core-UUID: [9341fc9e-7a4d-11df-92e6-6f7c82b8b4b4]
FreeSWITCH-Hostname: [sip1.lan.tssec.ru]
FreeSWITCH-IPv4: [192.168.50.11]
FreeSWITCH-IPv6: [::1]
Event-Date-Local: [2010-06-18 13:28:31]
Event-Date-GMT: [Fri, 18 Jun 2010 09:28:31 GMT]
Event-Date-Timestamp: [1276853311690473]
Event-Calling-File: [switch_channel.c]
Event-Calling-Function: [switch_channel_presence]
Event-Calling-Line-Number: [575]
Channel-State: [CS_EXECUTE]
Channel-Call-State: [ACTIVE]
Channel-State-Number: [4]
Channel-Name: [sofia/internal/229 at tssec.ru]
Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Channel-Presence-ID: [229 at tssec.ru]
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: [229]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [Nikolai Gabelok]
Caller-Caller-ID-Number: [229]
Caller-Callee-ID-Name: [215]
Caller-Callee-ID-Number: [215]
Caller-Network-Addr: [192.168.0.176]
Caller-ANI: [229]
Caller-Destination-Number: [215]
Caller-Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4]
Caller-Source: [mod_sofia]
Caller-Context: [default]
Caller-Channel-Name: [sofia/internal/229 at tssec.ru]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1276853309465278]
Caller-Channel-Created-Time: [1276853309465278]
Caller-Channel-Answered-Time: [1276853311690473]
Caller-Channel-Progress-Time: [1276853309605353]
Caller-Channel-Progress-Media-Time: [1276853309481286]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
proto: [src/switch_channel.c]
login: [src/switch_channel.c]
from: [229 at tssec.ru]
rpid: [unknown]
status: [answered]
event_type: [presence]
alt_event_type: [dialog]
presence-call-direction: [inbound]
event_count: [2]
2010-06-18 13:28:31.782523 [NOTICE] sofia_presence.c:1126 SEND PRESENCE
To: 100 at tssec.ru
From: 229 at tssec.ru
Call-ID: e2bc3098-8a58ff8d at 192.168.0.220
Profile: internal [internal]
2010-06-18 13:28:31.782523 [INFO] sofia_presence.c:682 IN
END_PRESENCE_SQL (internal)
2010-06-18 13:28:31.782523 [WARNING] sofia_presence.c:593 tssec.ru is
an alias, skipping
2010-06-18 13:28:31.782523 [WARNING] sofia_presence.c:600 external is
passive, skipping
2010-06-18 13:28:31.982630 [INFO] switch_rtp.c:2459 Auto Changing port
from 10.8.6.6:16535 to 10.8.6.6:16534
recv 610 bytes from udp/[192.168.0.176]:5060 at 09:30:12.688760:
------------------------------------------------------------------------
BYE sip:215 at 192.168.50.11:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-15ec1600
From: "Nikolai Gabelok" <sip:229 at tssec.ru>;tag=1e57eac0cc8bf959o0
To: "Elizarov Vladimir" <sip:215 at tssec.ru>;tag=D0rpvjgDaB86m
Call-ID: b4d6c80c-3143dc7d at 192.168.0.176
CSeq: 103 BYE
Max-Forwards: 70
Proxy-Authorization: Digest
username="229",realm="tssec.ru",nonce="13679dc0-7abc-11df-97d3-6f7c82b8b4b4",uri="sip:215 at 192.168.50.11:5060",algorithm=MD5,response="4bc49e6ad1c9587cccbb4ec6cd8378d2",qop=auth,nc=00000002,cnonce="4faa6b95"
User-Agent: Linksys/SPA921-5.1.8
Content-Length: 0
------------------------------------------------------------------------
2010-06-18 13:28:37.849779 [DEBUG] switch_channel.c:2257
(sofia/internal/229 at tssec.ru) Callstate Change ACTIVE -> HANGUP
2010-06-18 13:28:37.849779 [NOTICE] sofia.c:481 Hangup
sofia/internal/229 at tssec.ru [CS_EXECUTE] [NORMAL_CLEARING]
2010-06-18 13:28:37.849779 [DEBUG] switch_channel.c:2273 Send signal
sofia/internal/229 at tssec.ru [KILL]
2010-06-18 13:28:37.861786 [DEBUG] switch_ivr_bridge.c:478
sofia/internal/229 at tssec.ru ending bridge by request from read
function
2010-06-18 13:28:37.861786 [DEBUG] switch_ivr_bridge.c:472
sofia/internal/229 at tssec.ru ending bridge by request from write
function
2010-06-18 13:28:37.861786 [DEBUG] switch_ivr_bridge.c:565 BRIDGE
THREAD DONE [sofia/internal/229 at tssec.ru]
2010-06-18 13:28:37.861786 [DEBUG] switch_ivr_bridge.c:585 Send signal
sofia/internal/sip:215 at 10.8.6.6:5080 [BREAK]
2010-06-18 13:28:37.861786 [DEBUG] switch_core_session.c:643 Send
signal sofia/internal/sip:215 at 10.8.6.6:5080 [BREAK]
2010-06-18 13:28:37.861786 [DEBUG] switch_ivr_bridge.c:565 BRIDGE
THREAD DONE [sofia/internal/sip:215 at 10.8.6.6:5080]
2010-06-18 13:28:37.861786 [DEBUG] switch_ivr_bridge.c:585 Send signal
sofia/internal/229 at tssec.ru [BREAK]
2010-06-18 13:28:37.861786 [DEBUG] switch_channel.c:2257
(sofia/internal/sip:215 at 10.8.6.6:5080) Callstate Change ACTIVE ->
HANGUP
2010-06-18 13:28:37.861786 [NOTICE] switch_ivr_bridge.c:637 Hangup
sofia/internal/sip:215 at 10.8.6.6:5080 [CS_EXCHANGE_MEDIA]
[NORMAL_CLEARING]
2010-06-18 13:28:37.861786 [DEBUG] switch_channel.c:2273 Send signal
sofia/internal/sip:215 at 10.8.6.6:5080 [KILL]
2010-06-18 13:28:37.861786 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/sip:215 at 10.8.6.6:5080 [BREAK]
2010-06-18 13:28:37.861786 [DEBUG] switch_core_state_machine.c:351
(sofia/internal/sip:215 at 10.8.6.6:5080) State EXCHANGE_MEDIA going to
sleep
2010-06-18 13:28:37.861786 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:215 at 10.8.6.6:5080) Running State Change CS_HANGUP
2010-06-18 13:28:37.861786 [DEBUG] switch_core_state_machine.c:500
(sofia/internal/sip:215 at 10.8.6.6:5080) State HANGUP
2010-06-18 13:28:37.861786 [DEBUG] mod_sofia.c:435
sofia/internal/sip:215 at 10.8.6.6:5080 Overriding SIP cause 480 with 200
from the other leg
2010-06-18 13:28:37.861786 [DEBUG] mod_sofia.c:441 Channel
sofia/internal/sip:215 at 10.8.6.6:5080 hanging up, cause:
NORMAL_CLEARING
2010-06-18 13:28:37.861786 [DEBUG] switch_core_state_machine.c:348
(sofia/internal/229 at tssec.ru) State EXECUTE going to sleep
2010-06-18 13:28:37.861786 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/229 at tssec.ru) Running State Change CS_HANGUP
2010-06-18 13:28:37.861786 [DEBUG] switch_ivr_async.c:487 Stop
recording file /var/lib/freeswitch/recordings/229.215.2010-06-18-13-28.wav
2010-06-18 13:28:37.869790 [DEBUG] switch_core_media_bug.c:418
Removing BUG from sofia/internal/229 at tssec.ru
2010-06-18 13:28:37.869790 [DEBUG] switch_core_state_machine.c:500
(sofia/internal/229 at tssec.ru) State HANGUP
2010-06-18 13:28:37.877794 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/229 at tssec.ru [BREAK]
send 490 bytes to udp/[192.168.0.176]:5060 at 09:30:12.716775:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-15ec1600
From: "Nikolai Gabelok" <sip:229 at tssec.ru>;tag=1e57eac0cc8bf959o0
To: "Elizarov Vladimir" <sip:215 at tssec.ru>;tag=D0rpvjgDaB86m
Call-ID: b4d6c80c-3143dc7d at 192.168.0.176
CSeq: 103 BYE
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Content-Length: 0
------------------------------------------------------------------------
2010-06-18 13:28:37.877794 [DEBUG] mod_sofia.c:435
sofia/internal/229 at tssec.ru Overriding SIP cause 480 with 200 from the
other leg
2010-06-18 13:28:37.877794 [DEBUG] mod_sofia.c:441 Channel
sofia/internal/229 at tssec.ru hanging up, cause: NORMAL_CLEARING
2010-06-18 13:28:37.885798 [DEBUG] mod_sofia.c:484 Sending BYE to
sofia/internal/sip:215 at 10.8.6.6:5080
2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:46
sofia/internal/sip:215 at 10.8.6.6:5080 Standard HANGUP, cause:
NORMAL_CLEARING
2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:500
(sofia/internal/sip:215 at 10.8.6.6:5080) State HANGUP going to sleep
2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/sip:215 at 10.8.6.6:5080) State Change CS_HANGUP ->
CS_REPORTING
2010-06-18 13:28:37.885798 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/sip:215 at 10.8.6.6:5080 [BREAK]
2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/sip:215 at 10.8.6.6:5080) Running State Change
CS_REPORTING
2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:591
(sofia/internal/sip:215 at 10.8.6.6:5080) State REPORTING
2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:53
sofia/internal/sip:215 at 10.8.6.6:5080 Standard REPORTING, cause:
NORMAL_CLEARING
2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:591
(sofia/internal/sip:215 at 10.8.6.6:5080) State REPORTING going to sleep
2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:327
(sofia/internal/sip:215 at 10.8.6.6:5080) State Change CS_REPORTING ->
CS_DESTROY
2010-06-18 13:28:37.885798 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/sip:215 at 10.8.6.6:5080 [BREAK]
2010-06-18 13:28:37.885798 [DEBUG] switch_core_session.c:1171 Session
115 (sofia/internal/sip:215 at 10.8.6.6:5080) Locked, Waiting on external
entities
2010-06-18 13:28:37.885798 [NOTICE] switch_core_session.c:1189 Session
115 (sofia/internal/sip:215 at 10.8.6.6:5080) Ended
2010-06-18 13:28:37.885798 [NOTICE] switch_core_session.c:1191 Close
Channel sofia/internal/sip:215 at 10.8.6.6:5080 [CS_DESTROY]
2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:427
(sofia/internal/sip:215 at 10.8.6.6:5080) Callstate Change HANGUP -> DOWN
2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:430
(sofia/internal/sip:215 at 10.8.6.6:5080) Running State Change CS_DESTROY
2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/sip:215 at 10.8.6.6:5080) State DESTROY
2010-06-18 13:28:37.885798 [DEBUG] mod_sofia.c:350
sofia/internal/sip:215 at 10.8.6.6:5080 SOFIA DESTROY
2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:60
sofia/internal/sip:215 at 10.8.6.6:5080 Standard DESTROY
2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/sip:215 at 10.8.6.6:5080) State DESTROY going to sleep
send 612 bytes to udp/[10.8.6.6]:5080 at 09:30:12.724779:
------------------------------------------------------------------------
BYE sip:215 at 10.8.6.6:5080 SIP/2.0
Via: SIP/2.0/UDP 192.168.50.11;rport;branch=z9hG4bK8jSUvjrN60v4Q
Max-Forwards: 70
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=e9HFyD1g7KySg
To: <sip:215 at 10.8.6.6:5080>;tag=fyiai
Call-ID: ead3e978-f55e-122d-a480-00163efcbed2
CSeq: 132308367 BYE
Contact: <sip:mod_sofia at 192.168.50.11:5060>
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0
------------------------------------------------------------------------
2010-06-18 13:28:37.885798 [INFO] sofia_presence.c:663 IN
START_PRESENCE_SQL (internal)
2010-06-18 13:28:37.885798 [ERR] sofia_presence.c:672 DUMP PRESENCE SQL:
select sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'Call
Ended','unknown','tssec.ru',sip_presence.status,sip_presence.rpid from
sip_subscriptions left join sip_presence on
(sip_subscriptions.sub_to_user=sip_presence.sip_user and
sip_subscriptions.sub_to_host=sip_presence.sip_host and
sip_subscriptions.profile_name=sip_presence.profile_name) where
sip_subscriptions.expires > -1 and (event='presence' or
event='dialog') and sub_to_user='229' and (sub_to_host='tssec.ru' or
presence_hosts like '%tssec.ru%') and (sip_subscriptions.profile_name
= 'internal' or sip_subscriptions.presence_hosts !=
sip_subscriptions.sub_to_host)
EVENT DUMP:
Event-Name: [PRESENCE_IN]
Core-UUID: [9341fc9e-7a4d-11df-92e6-6f7c82b8b4b4]
FreeSWITCH-Hostname: [sip1.lan.tssec.ru]
FreeSWITCH-IPv4: [192.168.50.11]
FreeSWITCH-IPv6: [::1]
Event-Date-Local: [2010-06-18 13:28:37]
Event-Date-GMT: [Fri, 18 Jun 2010 09:28:37 GMT]
Event-Date-Timestamp: [1276853317861786]
Event-Calling-File: [switch_channel.c]
Event-Calling-Function: [switch_channel_presence]
Event-Calling-Line-Number: [575]
Channel-State: [CS_HANGUP]
Channel-Call-State: [HANGUP]
Channel-State-Number: [10]
Channel-Name: [sofia/internal/229 at tssec.ru]
Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Channel-Presence-ID: [229 at tssec.ru]
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: [229]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [Nikolai Gabelok]
Caller-Caller-ID-Number: [229]
Caller-Callee-ID-Name: [215]
Caller-Callee-ID-Number: [215]
Caller-Network-Addr: [192.168.0.176]
Caller-ANI: [229]
Caller-Destination-Number: [215]
Caller-Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4]
Caller-Source: [mod_sofia]
Caller-Context: [default]
Caller-Channel-Name: [sofia/internal/229 at tssec.ru]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1276853309465278]
Caller-Channel-Created-Time: [1276853309465278]
Caller-Channel-Answered-Time: [1276853311690473]
Caller-Channel-Progress-Time: [1276853309605353]
Caller-Channel-Progress-Media-Time: [1276853309481286]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
Other-Leg-Username: [229]
Other-Leg-Dialplan: [XML]
Other-Leg-Caller-ID-Name: [Nikolai Gabelok]
Other-Leg-Caller-ID-Number: [229]
Other-Leg-Callee-ID-Name: [215]
Other-Leg-Callee-ID-Number: [215]
Other-Leg-Network-Addr: [10.8.6.6]
Other-Leg-ANI: [229]
Other-Leg-Destination-Number: [215]
Other-Leg-Unique-ID: [1375a974-7abc-11df-97d5-6f7c82b8b4b4]
Other-Leg-Source: [mod_sofia]
Other-Leg-Context: [default]
Other-Leg-Channel-Name: [sofia/internal/sip:215 at 10.8.6.6:5080]
Other-Leg-Screen-Bit: [true]
Other-Leg-Privacy-Hide-Name: [false]
Other-Leg-Privacy-Hide-Number: [false]
proto: [src/switch_channel.c]
login: [src/switch_channel.c]
from: [229 at tssec.ru]
rpid: [unknown]
status: [CS_HANGUP]
event_type: [presence]
alt_event_type: [dialog]
presence-call-direction: [inbound]
event_count: [3]
2010-06-18 13:28:37.889801 [NOTICE] sofia_presence.c:1126 SEND PRESENCE
To: 100 at tssec.ru
From: 229 at tssec.ru
Call-ID: e2bc3098-8a58ff8d at 192.168.0.220
Profile: internal [internal]
2010-06-18 13:28:37.889801 [WARNING] sofia_presence.c:1350 send payload:
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="3"
state="full" entity="sip:229 at tssec.ru">
<dialog id="1371631e-7abc-11df-97d4-6f7c82b8b4b4" direction="initiator">
<state>terminated</state>
</dialog>
</dialog-info>
2010-06-18 13:28:37.889801 [INFO] sofia_presence.c:682 IN
END_PRESENCE_SQL (internal)
2010-06-18 13:28:37.889801 [WARNING] sofia_presence.c:593 tssec.ru is
an alias, skipping
2010-06-18 13:28:37.889801 [WARNING] sofia_presence.c:600 external is
passive, skipping
2010-06-18 13:28:37.889801 [INFO] sofia_presence.c:663 IN
START_PRESENCE_SQL (internal)
2010-06-18 13:28:37.889801 [ERR] sofia_presence.c:672 DUMP PRESENCE SQL:
select sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'NORMAL_CLEARING','unknown','tssec.ru',sip_presence.status,sip_presence.rpid
from sip_subscriptions left join sip_presence on
(sip_subscriptions.sub_to_user=sip_presence.sip_user and
sip_subscriptions.sub_to_host=sip_presence.sip_host and
sip_subscriptions.profile_name=sip_presence.profile_name) where
sip_subscriptions.expires > -1 and (event='presence' or
event='dialog') and sub_to_user='229' and (sub_to_host='tssec.ru' or
presence_hosts like '%tssec.ru%') and (sip_subscriptions.profile_name
= 'internal' or sip_subscriptions.presence_hosts !=
sip_subscriptions.sub_to_host)
EVENT DUMP:
Event-Name: [PRESENCE_IN]
Core-UUID: [9341fc9e-7a4d-11df-92e6-6f7c82b8b4b4]
FreeSWITCH-Hostname: [sip1.lan.tssec.ru]
FreeSWITCH-IPv4: [192.168.50.11]
FreeSWITCH-IPv6: [::1]
Event-Date-Local: [2010-06-18 13:28:37]
Event-Date-GMT: [Fri, 18 Jun 2010 09:28:37 GMT]
Event-Date-Timestamp: [1276853317869790]
Event-Calling-File: [switch_channel.c]
Event-Calling-Function: [switch_channel_presence]
Event-Calling-Line-Number: [575]
Channel-State: [CS_HANGUP]
Channel-Call-State: [HANGUP]
Channel-State-Number: [10]
Channel-Name: [sofia/internal/229 at tssec.ru]
Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Channel-Presence-ID: [229 at tssec.ru]
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: [229]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [Nikolai Gabelok]
Caller-Caller-ID-Number: [229]
Caller-Callee-ID-Name: [215]
Caller-Callee-ID-Number: [215]
Caller-Network-Addr: [192.168.0.176]
Caller-ANI: [229]
Caller-Destination-Number: [215]
Caller-Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4]
Caller-Source: [mod_sofia]
Caller-Context: [default]
Caller-Channel-Name: [sofia/internal/229 at tssec.ru]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1276853309465278]
Caller-Channel-Created-Time: [1276853309465278]
Caller-Channel-Answered-Time: [1276853311690473]
Caller-Channel-Progress-Time: [1276853309605353]
Caller-Channel-Progress-Media-Time: [1276853309481286]
Caller-Channel-Hangup-Time: [1276853317861786]
Caller-Channel-Transfer-Time: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
Other-Leg-Username: [229]
Other-Leg-Dialplan: [XML]
Other-Leg-Caller-ID-Name: [Nikolai Gabelok]
Other-Leg-Caller-ID-Number: [229]
Other-Leg-Callee-ID-Name: [215]
Other-Leg-Callee-ID-Number: [215]
Other-Leg-Network-Addr: [10.8.6.6]
Other-Leg-ANI: [229]
Other-Leg-Destination-Number: [215]
Other-Leg-Unique-ID: [1375a974-7abc-11df-97d5-6f7c82b8b4b4]
Other-Leg-Source: [mod_sofia]
Other-Leg-Context: [default]
Other-Leg-Channel-Name: [sofia/internal/sip:215 at 10.8.6.6:5080]
Other-Leg-Screen-Bit: [true]
Other-Leg-Privacy-Hide-Name: [false]
Other-Leg-Privacy-Hide-Number: [false]
proto: [src/switch_channel.c]
login: [src/switch_channel.c]
from: [229 at tssec.ru]
rpid: [unknown]
status: [NORMAL_CLEARING]
event_type: [presence]
alt_event_type: [dialog]
presence-call-direction: [inbound]
event_count: [4]
send 1044 bytes to udp/[192.168.0.220]:5060 at 09:30:12.728782:
------------------------------------------------------------------------
NOTIFY sip:100 at 192.168.0.220:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.50.11;rport;branch=z9hG4bK9UjmyD9r39jQK
Max-Forwards: 70
From: <sip:229 at tssec.ru>;tag=Be64rve6FSU1D
To: <sip:100 at tssec.ru>;tag=beeaf51cf0d364d9
Call-ID: e2bc3098-8a58ff8d at 192.168.0.220
CSeq: 132308350 NOTIFY
Contact: <sip:229 at 192.168.50.11:5060>
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Event: dialog
Allow-Events: talk, hold, presence, dialog, line-seize, call-info,
sla, include-session-description, presence.winfo, message-summary,
refer
Subscription-State: active;expires=1156
Content-Type: application/dialog-info+xml
Content-Length: 254
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="3"
state="full" entity="sip:229 at tssec.ru">
<dialog id="1371631e-7abc-11df-97d4-6f7c82b8b4b4" direction="initiator">
<state>terminated</state>
</dialog>
</dialog-info>
------------------------------------------------------------------------
2010-06-18 13:28:37.889801 [NOTICE] sofia_presence.c:1126 SEND PRESENCE
To: 100 at tssec.ru
From: 229 at tssec.ru
Call-ID: e2bc3098-8a58ff8d at 192.168.0.220
Profile: internal [internal]
2010-06-18 13:28:37.889801 [WARNING] sofia_presence.c:1350 send payload:
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="4"
state="full" entity="sip:229 at tssec.ru">
<dialog id="1371631e-7abc-11df-97d4-6f7c82b8b4b4" direction="initiator">
<state>terminated</state>
</dialog>
</dialog-info>
2010-06-18 13:28:37.889801 [INFO] sofia_presence.c:682 IN
END_PRESENCE_SQL (internal)
2010-06-18 13:28:37.889801 [WARNING] sofia_presence.c:593 tssec.ru is
an alias, skipping
2010-06-18 13:28:37.889801 [WARNING] sofia_presence.c:600 external is
passive, skipping
2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:46
sofia/internal/229 at tssec.ru Standard HANGUP, cause: NORMAL_CLEARING
2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:500
(sofia/internal/229 at tssec.ru) State HANGUP going to sleep
2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:333
(sofia/internal/229 at tssec.ru) State Change CS_HANGUP -> CS_REPORTING
2010-06-18 13:28:37.897805 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/229 at tssec.ru [BREAK]
2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/229 at tssec.ru) Running State Change CS_REPORTING
2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:591
(sofia/internal/229 at tssec.ru) State REPORTING
2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:53
sofia/internal/229 at tssec.ru Standard REPORTING, cause: NORMAL_CLEARING
2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:591
(sofia/internal/229 at tssec.ru) State REPORTING going to sleep
2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:327
(sofia/internal/229 at tssec.ru) State Change CS_REPORTING -> CS_DESTROY
2010-06-18 13:28:37.897805 [DEBUG] switch_core_session.c:1023 Send
signal sofia/internal/229 at tssec.ru [BREAK]
2010-06-18 13:28:37.897805 [DEBUG] switch_core_session.c:1171 Session
114 (sofia/internal/229 at tssec.ru) Locked, Waiting on external entities
2010-06-18 13:28:37.897805 [NOTICE] switch_core_session.c:1189 Session
114 (sofia/internal/229 at tssec.ru) Ended
2010-06-18 13:28:37.897805 [NOTICE] switch_core_session.c:1191 Close
Channel sofia/internal/229 at tssec.ru [CS_DESTROY]
recv 285 bytes from udp/[192.168.0.220]:5060 at 09:30:12.740788:
------------------------------------------------------------------------
SIP/2.0 200 OK
To: <sip:100 at tssec.ru>;tag=beeaf51cf0d364d9
From: <sip:229 at tssec.ru>;tag=Be64rve6FSU1D
Call-ID: e2bc3098-8a58ff8d at 192.168.0.220
CSeq: 132308350 NOTIFY
Via: SIP/2.0/UDP 192.168.50.11;branch=z9hG4bK9UjmyD9r39jQK
Server: Linksys/SPA962-6.1.3(a)
Content-Length: 0
------------------------------------------------------------------------
send 1044 bytes to udp/[192.168.0.220]:5060 at 09:30:12.740788:
------------------------------------------------------------------------
NOTIFY sip:100 at 192.168.0.220:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.50.11;rport;branch=z9hG4bKa5BD08Sv0j99e
Max-Forwards: 70
From: <sip:229 at tssec.ru>;tag=Be64rve6FSU1D
To: <sip:100 at tssec.ru>;tag=beeaf51cf0d364d9
Call-ID: e2bc3098-8a58ff8d at 192.168.0.220
CSeq: 132308351 NOTIFY
Contact: <sip:229 at 192.168.50.11:5060>
User-Agent: FreeSWITCH-mod_sofia/1.0.head-git-
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, precondition, path, replaces
Event: dialog
Allow-Events: talk, hold, presence, dialog, line-seize, call-info,
sla, include-session-description, presence.winfo, message-summary,
refer
Subscription-State: active;expires=1156
Content-Type: application/dialog-info+xml
Content-Length: 254
<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="4"
state="full" entity="sip:229 at tssec.ru">
<dialog id="1371631e-7abc-11df-97d4-6f7c82b8b4b4" direction="initiator">
<state>terminated</state>
</dialog>
</dialog-info>
------------------------------------------------------------------------
2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:427
(sofia/internal/229 at tssec.ru) Callstate Change HANGUP -> DOWN
2010-06-18 13:28:37.901807 [DEBUG] switch_core_state_machine.c:430
(sofia/internal/229 at tssec.ru) Running State Change CS_DESTROY
2010-06-18 13:28:37.901807 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/229 at tssec.ru) State DESTROY
2010-06-18 13:28:37.901807 [DEBUG] mod_sofia.c:350
sofia/internal/229 at tssec.ru SOFIA DESTROY
2010-06-18 13:28:37.901807 [DEBUG] switch_core_state_machine.c:60
sofia/internal/229 at tssec.ru Standard DESTROY
2010-06-18 13:28:37.901807 [DEBUG] switch_core_state_machine.c:440
(sofia/internal/229 at tssec.ru) State DESTROY going to sleep
recv 285 bytes from udp/[192.168.0.220]:5060 at 09:30:12.752794:
------------------------------------------------------------------------
SIP/2.0 200 OK
To: <sip:100 at tssec.ru>;tag=beeaf51cf0d364d9
From: <sip:229 at tssec.ru>;tag=Be64rve6FSU1D
Call-ID: e2bc3098-8a58ff8d at 192.168.0.220
CSeq: 132308351 NOTIFY
Via: SIP/2.0/UDP 192.168.50.11;branch=z9hG4bKa5BD08Sv0j99e
Server: Linksys/SPA962-6.1.3(a)
Content-Length: 0
------------------------------------------------------------------------
recv 328 bytes from udp/[10.8.6.6]:5080 at 09:30:12.812827:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP
192.168.50.11;received=192.168.50.11;rport=5060;branch=z9hG4bK8jSUvjrN60v4Q
To: <sip:215 at 10.8.6.6:5080>;tag=fyiai
From: "Nikolai Gabelok" <sip:229 at 192.168.50.11>;tag=e9HFyD1g7KySg
Call-ID: ead3e978-f55e-122d-a480-00163efcbed2
CSeq: 132308367 BYE
Server: Twinkle/1.4.2
Content-Length: 0
------------------------------------------------------------------------
On Fri, Jun 18, 2010 at 11:35 AM, Vladimir Elizarov
<xengelpublicx at gmail.com> wrote:
> i'm change dialplan with call_limit:
> <extension name="Local_Extension">
> <condition field="destination_number" expression="^([1-2][0-2][0-9])$">
> <action application="set" data="dialed_extension=$1"/>
> <action application="export" data="dialed_extension=$1"/>
> <action application="export" data="RECORD_STEREO=true"/>
> <action application="bind_meta_app" data="1 b s execute_extension::dx
> XML features"/>
> <action application="bind_meta_app" data="2 a s
> record_session::$${recordprefix}/${caller_id_number}.${destination_number}.${strftime(%Y-%m-%d-%H-%M)}.wav"/>
> <action application="hash"
> data="insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}"/>
> <action application="hash"
> data="insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}"/>
> <action application="set"
> data="called_party_callgroup=${user_data(${dialed_extension}@${domain_name}
> var callgroup)}"/>
> <action application="hash"
> data="insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}"/>
> </condition>
> <condition field="destination_number" expression="^100$" break="on-true">
> <action application="set" data="call_timeout=60"/>
> <action application="answer"/>
> <action application="set" data="transfer_ringback=$${hold_music}"/>
> <action application="bridge" data="user/${dialed_extension}@$${domain}"/>
> </condition>
> <condition field="destination_number" expression="^${caller_id_number}$">
> <action application="set" data="voicemail_authorized=${sip_authorized}"/>
> <action application="answer"/>
> <action application="sleep" data="1000"/>
> <action application="voicemail" data="check default $${domain}
> ${dialed_extension}"/>
> <anti-action application="limit" data="$${domain} ${destination_number} 1"/>
> <anti-action application="set" data="transfer_ringback=$${hold_music}"/>
> <anti-action application="set" data="ringback=$${ru-ring}"/>
> <anti-action application="set" data="call_timeout=15"/>
> <anti-action application="set" data="hangup_after_bridge=true"/>
> <anti-action application="set" data="continue_on_fail=true"/>
> <anti-action application="bridge"
> data="{ignore_early_media=true}${sofia_contact(internal/${dialed_extension}@$${domain})}"/>
> <anti-action application="transfer"
> data="not_answer-${dialed_extension} XML default"/>
> </condition>
> </extension>
>
> then the state spa932 phone for incoming calls stopped working. Always
> light green.
>
> On Thu, Jun 17, 2010 at 4:57 PM, Vladimir Elizarov
> <xengelpublicx at gmail.com> wrote:
>> I found a bug in the presence of the linksys spa932 (configure this
>> article: http://wiki.freeswitch.org/wiki/Interop_List#Linksys_SPA932).
>> If during the
>> conversation (lamp on) to the subscriber, someone called, the lamp on
>> the panel goes into the state off. Who can verify whether he has
>> reproduced the same problem?
>>
>> Unit key: fnc=blf+sd+cp;sub=110@$PROXY
>>
>> freeswitch 1.0.6 (git 10 06 2010)
>>
>> Linksys spa962:
>> Software Version: 6.1.3(a)
>> Hardware Version: 1.0.3(917f)
>>
>> Linksys spa932
>> Unit Enable: Yes Unit Online: Yes
>> Subscribe Expires: 600 Subscribe Retry Interval: 6
>> HW Version: 1.0.6 SW Version: 2.0.2
>>
>> Configure image:
>> http://img192.imageshack.us/img192/2320/linksysspa932.png
>>
>> --
>> Best regards, Vladimir Elizarov
>>
>
>
>
> --
> Best regards, Vladimir Elizarov
>
--
Best regards, Vladimir Elizarov
More information about the FreeSWITCH-users
mailing list