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
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@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
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@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@tssec.ru>;tag=Be64rve6FSU1D To: <sip:100@tssec.ru>;tag=beeaf51cf0d364d9 Call-ID: e2bc3098-8a58ff8d@192.168.0.220 CSeq: 132308348 NOTIFY Contact: <sip:229@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@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@tssec.ru>;tag=beeaf51cf0d364d9 From: <sip:229@tssec.ru>;tag=Be64rve6FSU1D Call-ID: e2bc3098-8a58ff8d@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@192.168.50.11@internal> recv 927 bytes from udp/[192.168.0.176]:5060 at 09:30:04.240224: ------------------------------------------------------------------------ INVITE sip:215@tssec.ru SIP/2.0 Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-cd8a0332 From: "Nikolai Gabelok" <sip:229@tssec.ru>;tag=1e57eac0cc8bf959o0 To: "Elizarov Vladimir" <sip:215@tssec.ru> Call-ID: b4d6c80c-3143dc7d@192.168.0.176 CSeq: 101 INVITE Max-Forwards: 70 Contact: "Nikolai Gabelok" <sip:229@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@tssec.ru>;tag=1e57eac0cc8bf959o0 To: "Elizarov Vladimir" <sip:215@tssec.ru> Call-ID: b4d6c80c-3143dc7d@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@tssec.ru>;tag=1e57eac0cc8bf959o0 To: "Elizarov Vladimir" <sip:215@tssec.ru>;tag=cQZXtQZ9c2HmS Call-ID: b4d6c80c-3143dc7d@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@tssec.ru SIP/2.0 Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-cd8a0332 From: "Nikolai Gabelok" <sip:229@tssec.ru>;tag=1e57eac0cc8bf959o0 To: "Elizarov Vladimir" <sip:215@tssec.ru>;tag=cQZXtQZ9c2HmS Call-ID: b4d6c80c-3143dc7d@192.168.0.176 CSeq: 101 ACK Max-Forwards: 70 Contact: "Nikolai Gabelok" <sip:229@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@tssec.ru SIP/2.0 Via: SIP/2.0/UDP 192.168.0.176:5060;branch=z9hG4bK-5520e68e From: "Nikolai Gabelok" <sip:229@tssec.ru>;tag=1e57eac0cc8bf959o0 To: "Elizarov Vladimir" <sip:215@tssec.ru> Call-ID: b4d6c80c-3143dc7d@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@tssec.ru",algorithm=MD5,response="78382843426af5a5fb18bc30de5953fb",qop=auth,nc=00000001,cnonce="4faa6b95" Contact: "Nikolai Gabelok" <sip:229@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@tssec.ru>;tag=1e57eac0cc8bf959o0 To: "Elizarov Vladimir" <sip:215@tssec.ru> Call-ID: b4d6c80c-3143dc7d@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@tssec.ru [1371631e-7abc-11df-97d4-6f7c82b8b4b4] 2010-06-18 13:28:29.465278 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/229@tssec.ru) Running State Change CS_NEW 2010-06-18 13:28:29.465278 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/229@tssec.ru) State NEW 2010-06-18 13:28:29.469280 [DEBUG] sofia.c:4281 Channel sofia/internal/229@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@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@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@tssec.ru [BREAK] 2010-06-18 13:28:29.469280 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/229@tssec.ru) Running State Change CS_INIT 2010-06-18 13:28:29.469280 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/229@tssec.ru) State INIT 2010-06-18 13:28:29.469280 [DEBUG] mod_sofia.c:83 sofia/internal/229@tssec.ru SOFIA INIT 2010-06-18 13:28:29.469280 [DEBUG] mod_sofia.c:117 (sofia/internal/229@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@tssec.ru [BREAK] 2010-06-18 13:28:29.469280 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/229@tssec.ru) State INIT going to sleep 2010-06-18 13:28:29.469280 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/229@tssec.ru) Running State Change CS_ROUTING 2010-06-18 13:28:29.469280 [DEBUG] switch_channel.c:1470 (sofia/internal/229@tssec.ru) Callstate Change DOWN -> RINGING 2010-06-18 13:28:29.469280 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/229@tssec.ru) State ROUTING 2010-06-18 13:28:29.469280 [DEBUG] switch_channel.c:1329 (sofia/internal/229@tssec.ru) Callstate Change RINGING -> ACTIVE 2010-06-18 13:28:29.469280 [DEBUG] mod_sofia.c:140 sofia/internal/229@tssec.ru SOFIA ROUTING 2010-06-18 13:28:29.469280 [DEBUG] switch_core_state_machine.c:77 sofia/internal/229@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@tssec.ru parsing [default->unloop] continue=false Dialplan: sofia/internal/229@tssec.ru Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/229@tssec.ru Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/229@tssec.ru parsing [default->time of day routing] continue=true Dialplan: sofia/internal/229@tssec.ru Date/Time Match (PASS) [time of day routing] break=on-false Dialplan: sofia/internal/229@tssec.ru Action set(status=open) Dialplan: sofia/internal/229@tssec.ru Date/Time Match (FAIL) [time of day routing] break=on-false Dialplan: sofia/internal/229@tssec.ru parsing [default->IVR] continue=false Dialplan: sofia/internal/229@tssec.ru Regex (FAIL) [IVR] destination_number(215) =~ /^(ivr|5000)$/ break=on-false Dialplan: sofia/internal/229@tssec.ru parsing [default->delay_echo] continue=false Dialplan: sofia/internal/229@tssec.ru Regex (FAIL) [delay_echo] destination_number(215) =~ /^echo123$|^123$/ break=on-false Dialplan: sofia/internal/229@tssec.ru parsing [default->delay_echo_next] continue=false Dialplan: sofia/internal/229@tssec.ru Regex (FAIL) [delay_echo_next] destination_number(215) =~ /after_echo/ break=on-false Dialplan: sofia/internal/229@tssec.ru parsing [default->global-intercept] continue=false Dialplan: sofia/internal/229@tssec.ru Regex (FAIL) [global-intercept] destination_number(215) =~ /^\*\*$/ break=on-false Dialplan: sofia/internal/229@tssec.ru parsing [default->group-intercept] continue=false Dialplan: sofia/internal/229@tssec.ru Regex (FAIL) [group-intercept] destination_number(215) =~ /^\*$/ break=on-false Dialplan: sofia/internal/229@tssec.ru parsing [default->extension-intercept] continue=false Dialplan: sofia/internal/229@tssec.ru Regex (FAIL) [extension-intercept] destination_number(215) =~ /^\*(\d+)$/ break=on-false Dialplan: sofia/internal/229@tssec.ru parsing [default->sales] continue=false Dialplan: sofia/internal/229@tssec.ru Regex (FAIL) [sales] destination_number(215) =~ /^sales$/ break=on-false Dialplan: sofia/internal/229@tssec.ru parsing [default->integrations] continue=false Dialplan: sofia/internal/229@tssec.ru Regex (FAIL) [integrations] destination_number(215) =~ /^integrations$/ break=on-false Dialplan: sofia/internal/229@tssec.ru parsing [default->operators] continue=false Dialplan: sofia/internal/229@tssec.ru Regex (FAIL) [operators] destination_number(215) =~ /^operators$/ break=on-false Dialplan: sofia/internal/229@tssec.ru parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/229@tssec.ru Regex (PASS) [Local_Extension] destination_number(215) =~ /^([1-2][0-2][0-9])$/ break=on-false Dialplan: sofia/internal/229@tssec.ru Action set(dialed_extension=215) Dialplan: sofia/internal/229@tssec.ru Action export(dialed_extension=215) Dialplan: sofia/internal/229@tssec.ru Action export(RECORD_STEREO=true) Dialplan: sofia/internal/229@tssec.ru Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/229@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@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@tssec.ru Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/229@tssec.ru Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/229@tssec.ru Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/229@tssec.ru Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/229@tssec.ru Regex (FAIL) [Local_Extension] destination_number(215) =~ /^100$/ break=on-true Dialplan: sofia/internal/229@tssec.ru Regex (FAIL) [Local_Extension] destination_number(215) =~ /^229$/ break=on-false Dialplan: sofia/internal/229@tssec.ru ANTI-Action limit(tssec.ru ${destination_number} 1) Dialplan: sofia/internal/229@tssec.ru ANTI-Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/229@tssec.ru ANTI-Action set(ringback=%(800,3200,425,0)) Dialplan: sofia/internal/229@tssec.ru ANTI-Action set(call_timeout=15) Dialplan: sofia/internal/229@tssec.ru ANTI-Action set(hangup_after_bridge=true) Dialplan: sofia/internal/229@tssec.ru ANTI-Action set(continue_on_fail=true) Dialplan: sofia/internal/229@tssec.ru ANTI-Action bridge({ignore_early_media=true}${sofia_contact(internal/${dialed_extension}@tssec.ru)}) Dialplan: sofia/internal/229@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@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@tssec.ru [BREAK] 2010-06-18 13:28:29.473282 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/229@tssec.ru) State ROUTING going to sleep 2010-06-18 13:28:29.473282 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/229@tssec.ru) Running State Change CS_EXECUTE 2010-06-18 13:28:29.473282 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/229@tssec.ru) State EXECUTE 2010-06-18 13:28:29.473282 [DEBUG] mod_sofia.c:233 sofia/internal/229@tssec.ru SOFIA EXECUTE 2010-06-18 13:28:29.473282 [DEBUG] switch_core_state_machine.c:157 sofia/internal/229@tssec.ru Standard EXECUTE EXECUTE sofia/internal/229@tssec.ru set(status=open) 2010-06-18 13:28:29.473282 [DEBUG] mod_dptools.c:834 sofia/internal/229@tssec.ru SET [status]=[open] EXECUTE sofia/internal/229@tssec.ru set(dialed_extension=215) 2010-06-18 13:28:29.473282 [DEBUG] mod_dptools.c:834 sofia/internal/229@tssec.ru SET [dialed_extension]=[215] EXECUTE sofia/internal/229@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@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@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@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@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@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@tssec.ru] Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4] Call-Direction: [inbound] Presence-Call-Direction: [inbound] Channel-Presence-ID: [229@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@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@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@tssec.ru From: 229@tssec.ru Call-ID: e2bc3098-8a58ff8d@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@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@tssec.ru] Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4] Call-Direction: [inbound] Presence-Call-Direction: [inbound] Channel-Presence-ID: [229@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@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@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@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@tssec.ru>;tag=Be64rve6FSU1D To: <sip:100@tssec.ru>;tag=beeaf51cf0d364d9 Call-ID: e2bc3098-8a58ff8d@192.168.0.220 CSeq: 132308349 NOTIFY Contact: <sip:229@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@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@tssec.ru From: 229@tssec.ru Call-ID: e2bc3098-8a58ff8d@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@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@tssec.ru) Callstate Change ACTIVE -> EARLY 2010-06-18 13:28:29.481286 [DEBUG] switch_core_session.c:643 Send signal sofia/internal/229@tssec.ru [BREAK] EXECUTE sofia/internal/229@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@tssec.ru EXECUTE sofia/internal/229@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@tssec.ru>;tag=1e57eac0cc8bf959o0 To: "Elizarov Vladimir" <sip:215@tssec.ru>;tag=D0rpvjgDaB86m Call-ID: b4d6c80c-3143dc7d@192.168.0.176 CSeq: 102 INVITE Contact: <sip:215@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@tssec.ru skipping state [early][183] EXECUTE sofia/internal/229@tssec.ru hash(insert/tssec.ru-last_dial_ext/215/1371631e-7abc-11df-97d4-6f7c82b8b4b4) EXECUTE sofia/internal/229@tssec.ru set(called_party_callgroup=1) 2010-06-18 13:28:29.481286 [DEBUG] mod_dptools.c:834 sofia/internal/229@tssec.ru SET [called_party_callgroup]=[1] EXECUTE sofia/internal/229@tssec.ru hash(insert/tssec.ru-last_dial/1/1371631e-7abc-11df-97d4-6f7c82b8b4b4) EXECUTE sofia/internal/229@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@tssec.ru set(transfer_ringback=local_stream://moh) 2010-06-18 13:28:29.493293 [DEBUG] mod_dptools.c:834 sofia/internal/229@tssec.ru SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/229@tssec.ru set(ringback=%(800,3200,425,0)) 2010-06-18 13:28:29.493293 [DEBUG] mod_dptools.c:834 sofia/internal/229@tssec.ru SET [ringback]=[%(800,3200,425,0)] EXECUTE sofia/internal/229@tssec.ru set(call_timeout=15) 2010-06-18 13:28:29.493293 [DEBUG] mod_dptools.c:834 sofia/internal/229@tssec.ru SET [call_timeout]=[15] EXECUTE sofia/internal/229@tssec.ru set(hangup_after_bridge=true) 2010-06-18 13:28:29.493293 [DEBUG] mod_dptools.c:834 sofia/internal/229@tssec.ru SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/229@tssec.ru set(continue_on_fail=true) 2010-06-18 13:28:29.493293 [DEBUG] mod_dptools.c:834 sofia/internal/229@tssec.ru SET [continue_on_fail]=[true] EXECUTE sofia/internal/229@tssec.ru bridge({ignore_early_media=true}sofia/internal/sip:215@10.8.6.6:5080,sofia/internal/sip:215@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@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@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@10.8.6.6:5080 [BREAK] 2010-06-18 13:28:29.493293 [NOTICE] switch_channel.c:772 New Channel sofia/internal/sip:215@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@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@192.168.1.118:5060 [BREAK] 2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:215@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@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@10.8.6.6:5080) State INIT 2010-06-18 13:28:29.493293 [DEBUG] mod_sofia.c:83 sofia/internal/sip:215@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@192.168.1.118:5060) State INIT 2010-06-18 13:28:29.493293 [DEBUG] mod_sofia.c:83 sofia/internal/sip:215@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@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@192.168.50.11>;tag=e9HFyD1g7KySg To: <sip:215@10.8.6.6:5080> Call-ID: ead3e978-f55e-122d-a480-00163efcbed2 CSeq: 132308366 INVITE Contact: <sip:mod_sofia@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@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@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@10.8.6.6:5080 [BREAK] 2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/sip:215@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@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@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@10.8.6.6:5080) State ROUTING 2010-06-18 13:28:29.493293 [DEBUG] switch_channel.c:1329 (sofia/internal/sip:215@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@10.8.6.6:5080 SOFIA ROUTING 2010-06-18 13:28:29.493293 [DEBUG] switch_ivr_originate.c:64 (sofia/internal/sip:215@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@10.8.6.6:5080 [BREAK] 2010-06-18 13:28:29.493293 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/sip:215@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@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@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@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@tssec.ru>;tag=beeaf51cf0d364d9 From: <sip:229@tssec.ru>;tag=Be64rve6FSU1D Call-ID: e2bc3098-8a58ff8d@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@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@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@192.168.1.118:5060 [BREAK] 2010-06-18 13:28:29.497295 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/sip:215@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@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@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@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@192.168.50.11>;tag=FjB8Z8Hm4vmcc To: <sip:215@192.168.1.118:5060> Call-ID: ead485ce-f55e-122d-a480-00163efcbed2 CSeq: 132308366 INVITE Contact: <sip:mod_sofia@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@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@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@192.168.1.118:5060) State ROUTING 2010-06-18 13:28:29.501297 [DEBUG] switch_channel.c:1329 (sofia/internal/sip:215@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@192.168.1.118:5060 SOFIA ROUTING 2010-06-18 13:28:29.501297 [DEBUG] switch_ivr_originate.c:64 (sofia/internal/sip:215@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@192.168.1.118:5060 [BREAK] 2010-06-18 13:28:29.501297 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/sip:215@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@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@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@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@192.168.50.11>;tag=FjB8Z8Hm4vmcc To: <sip:215@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@192.168.50.11>;tag=FjB8Z8Hm4vmcc To: <sip:215@192.168.1.118:5060>;tag=800c08bf2979df11bda80013d4bfa980 Call-ID: ead485ce-f55e-122d-a480-00163efcbed2 CSeq: 132308366 INVITE Contact: <sip:215@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@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@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@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@8000hz 1 channel 20ms 2010-06-18 13:28:29.561329 [DEBUG] switch_core_codec.c:122 sofia/internal/229@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@10.8.6.6:5080> From: "Nikolai Gabelok" <sip:229@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@10.8.6.6:5080>;tag=fyiai From: "Nikolai Gabelok" <sip:229@192.168.50.11>;tag=e9HFyD1g7KySg Call-ID: ead3e978-f55e-122d-a480-00163efcbed2 CSeq: 132308366 INVITE Contact: <sip:215@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@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@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@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@10.8.6.6:5080>;tag=fyiai From: "Nikolai Gabelok" <sip:229@192.168.50.11>;tag=e9HFyD1g7KySg Call-ID: ead3e978-f55e-122d-a480-00163efcbed2 CSeq: 132308366 INVITE Contact: <sip:215@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@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@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@192.168.50.11>;tag=e9HFyD1g7KySg To: <sip:215@10.8.6.6:5080>;tag=fyiai Call-ID: ead3e978-f55e-122d-a480-00163efcbed2 CSeq: 132308366 ACK Contact: <sip:mod_sofia@192.168.50.11:5060> Content-Length: 0 ------------------------------------------------------------------------ 2010-06-18 13:28:31.670463 [DEBUG] sofia.c:4281 Channel sofia/internal/sip:215@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@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@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@tssec.ru [BREAK] 2010-06-18 13:28:31.670463 [NOTICE] sofia.c:4831 Channel [sofia/internal/sip:215@10.8.6.6:5080] has been answered 2010-06-18 13:28:31.682469 [DEBUG] switch_core_codec.c:146 sofia/internal/229@tssec.ru Restore previous codec PCMA:8. 2010-06-18 13:28:31.682469 [DEBUG] switch_channel.c:2257 (sofia/internal/sip:215@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@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@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@192.168.1.118:5060 [BREAK] 2010-06-18 13:28:31.682469 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:215@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@192.168.1.118:5060) State HANGUP 2010-06-18 13:28:31.682469 [DEBUG] mod_sofia.c:441 Channel sofia/internal/sip:215@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@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@tssec.ru [BREAK] 2010-06-18 13:28:31.690473 [DEBUG] switch_channel.c:2485 (sofia/internal/229@tssec.ru) Callstate Change EARLY -> ACTIVE 2010-06-18 13:28:31.690473 [NOTICE] switch_ivr_originate.c:3216 Channel [sofia/internal/229@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@10.8.6.6:5080] 2010-06-18 13:28:31.690473 [DEBUG] switch_core_session.c:643 Send signal sofia/internal/sip:215@10.8.6.6:5080 [BREAK] 2010-06-18 13:28:31.690473 [DEBUG] switch_core_session.c:643 Send signal sofia/internal/229@tssec.ru [BREAK] 2010-06-18 13:28:31.690473 [DEBUG] switch_ivr_bridge.c:1182 (sofia/internal/sip:215@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@tssec.ru>;tag=1e57eac0cc8bf959o0 To: "Elizarov Vladimir" <sip:215@tssec.ru>;tag=D0rpvjgDaB86m Call-ID: b4d6c80c-3143dc7d@192.168.0.176 CSeq: 102 INVITE Contact: <sip:215@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@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@10.8.6.6:5080 [BREAK] 2010-06-18 13:28:31.690473 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:215@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@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@192.168.1.118:5060 2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:46 sofia/internal/sip:215@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@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@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@192.168.1.118:5060 [BREAK] 2010-06-18 13:28:31.702480 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:215@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@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@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@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@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@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@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@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@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@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@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@192.168.1.118:5060) State DESTROY 2010-06-18 13:28:31.702480 [DEBUG] mod_sofia.c:350 sofia/internal/sip:215@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@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@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@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@192.168.50.11>;tag=FjB8Z8Hm4vmcc To: <sip:215@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@192.168.50.11>;tag=FjB8Z8Hm4vmcc To: <sip:215@192.168.1.118:5060>;tag=800c08bf2979df11bda80013d4bfa980 Call-ID: ead485ce-f55e-122d-a480-00163efcbed2 CSeq: 132308366 CANCEL Contact: <sip:215@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@192.168.50.11>;tag=FjB8Z8Hm4vmcc To: <sip:215@192.168.1.118:5060>;tag=800c08bf2979df11bda80013d4bfa980 Call-ID: ead485ce-f55e-122d-a480-00163efcbed2 CSeq: 132308366 INVITE Contact: <sip:215@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@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@192.168.50.11>;tag=FjB8Z8Hm4vmcc To: <sip:215@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@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@tssec.ru>;tag=1e57eac0cc8bf959o0 To: "Elizarov Vladimir" <sip:215@tssec.ru>;tag=D0rpvjgDaB86m Call-ID: b4d6c80c-3143dc7d@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@tssec.ru",algorithm=MD5,response="78382843426af5a5fb18bc30de5953fb",qop=auth,nc=00000001,cnonce="4faa6b95" Contact: "Nikolai Gabelok" <sip:229@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@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@10.8.6.6:5080 [BREAK] 2010-06-18 13:28:31.742501 [DEBUG] switch_core_session.c:704 Send signal sofia/internal/229@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@tssec.ru] Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4] Call-Direction: [inbound] Presence-Call-Direction: [inbound] Channel-Presence-ID: [229@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@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@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@tssec.ru From: 229@tssec.ru Call-ID: e2bc3098-8a58ff8d@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@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@tssec.ru>;tag=1e57eac0cc8bf959o0 To: "Elizarov Vladimir" <sip:215@tssec.ru>;tag=D0rpvjgDaB86m Call-ID: b4d6c80c-3143dc7d@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@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@tssec.ru) Callstate Change ACTIVE -> HANGUP 2010-06-18 13:28:37.849779 [NOTICE] sofia.c:481 Hangup sofia/internal/229@tssec.ru [CS_EXECUTE] [NORMAL_CLEARING] 2010-06-18 13:28:37.849779 [DEBUG] switch_channel.c:2273 Send signal sofia/internal/229@tssec.ru [KILL] 2010-06-18 13:28:37.861786 [DEBUG] switch_ivr_bridge.c:478 sofia/internal/229@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@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@tssec.ru] 2010-06-18 13:28:37.861786 [DEBUG] switch_ivr_bridge.c:585 Send signal sofia/internal/sip:215@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@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@10.8.6.6:5080] 2010-06-18 13:28:37.861786 [DEBUG] switch_ivr_bridge.c:585 Send signal sofia/internal/229@tssec.ru [BREAK] 2010-06-18 13:28:37.861786 [DEBUG] switch_channel.c:2257 (sofia/internal/sip:215@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@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@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@10.8.6.6:5080 [BREAK] 2010-06-18 13:28:37.861786 [DEBUG] switch_core_state_machine.c:351 (sofia/internal/sip:215@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@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@10.8.6.6:5080) State HANGUP 2010-06-18 13:28:37.861786 [DEBUG] mod_sofia.c:435 sofia/internal/sip:215@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@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@tssec.ru) State EXECUTE going to sleep 2010-06-18 13:28:37.861786 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/229@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@tssec.ru 2010-06-18 13:28:37.869790 [DEBUG] switch_core_state_machine.c:500 (sofia/internal/229@tssec.ru) State HANGUP 2010-06-18 13:28:37.877794 [DEBUG] switch_core_session.c:1023 Send signal sofia/internal/229@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@tssec.ru>;tag=1e57eac0cc8bf959o0 To: "Elizarov Vladimir" <sip:215@tssec.ru>;tag=D0rpvjgDaB86m Call-ID: b4d6c80c-3143dc7d@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@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@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@10.8.6.6:5080 2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:46 sofia/internal/sip:215@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@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@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@10.8.6.6:5080 [BREAK] 2010-06-18 13:28:37.885798 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:215@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@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@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@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@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@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@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@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@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@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@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@10.8.6.6:5080) State DESTROY 2010-06-18 13:28:37.885798 [DEBUG] mod_sofia.c:350 sofia/internal/sip:215@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@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@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@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@192.168.50.11>;tag=e9HFyD1g7KySg To: <sip:215@10.8.6.6:5080>;tag=fyiai Call-ID: ead3e978-f55e-122d-a480-00163efcbed2 CSeq: 132308367 BYE Contact: <sip:mod_sofia@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@tssec.ru] Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4] Call-Direction: [inbound] Presence-Call-Direction: [inbound] Channel-Presence-ID: [229@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@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@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@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@tssec.ru From: 229@tssec.ru Call-ID: e2bc3098-8a58ff8d@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@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@tssec.ru] Unique-ID: [1371631e-7abc-11df-97d4-6f7c82b8b4b4] Call-Direction: [inbound] Presence-Call-Direction: [inbound] Channel-Presence-ID: [229@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@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@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@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@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@tssec.ru>;tag=Be64rve6FSU1D To: <sip:100@tssec.ru>;tag=beeaf51cf0d364d9 Call-ID: e2bc3098-8a58ff8d@192.168.0.220 CSeq: 132308350 NOTIFY Contact: <sip:229@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@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@tssec.ru From: 229@tssec.ru Call-ID: e2bc3098-8a58ff8d@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@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@tssec.ru Standard HANGUP, cause: NORMAL_CLEARING 2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:500 (sofia/internal/229@tssec.ru) State HANGUP going to sleep 2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/229@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@tssec.ru [BREAK] 2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/229@tssec.ru) Running State Change CS_REPORTING 2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:591 (sofia/internal/229@tssec.ru) State REPORTING 2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:53 sofia/internal/229@tssec.ru Standard REPORTING, cause: NORMAL_CLEARING 2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:591 (sofia/internal/229@tssec.ru) State REPORTING going to sleep 2010-06-18 13:28:37.897805 [DEBUG] switch_core_state_machine.c:327 (sofia/internal/229@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@tssec.ru [BREAK] 2010-06-18 13:28:37.897805 [DEBUG] switch_core_session.c:1171 Session 114 (sofia/internal/229@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@tssec.ru) Ended 2010-06-18 13:28:37.897805 [NOTICE] switch_core_session.c:1191 Close Channel sofia/internal/229@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@tssec.ru>;tag=beeaf51cf0d364d9 From: <sip:229@tssec.ru>;tag=Be64rve6FSU1D Call-ID: e2bc3098-8a58ff8d@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@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@tssec.ru>;tag=Be64rve6FSU1D To: <sip:100@tssec.ru>;tag=beeaf51cf0d364d9 Call-ID: e2bc3098-8a58ff8d@192.168.0.220 CSeq: 132308351 NOTIFY Contact: <sip:229@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@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@tssec.ru) Callstate Change HANGUP -> DOWN 2010-06-18 13:28:37.901807 [DEBUG] switch_core_state_machine.c:430 (sofia/internal/229@tssec.ru) Running State Change CS_DESTROY 2010-06-18 13:28:37.901807 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/229@tssec.ru) State DESTROY 2010-06-18 13:28:37.901807 [DEBUG] mod_sofia.c:350 sofia/internal/229@tssec.ru SOFIA DESTROY 2010-06-18 13:28:37.901807 [DEBUG] switch_core_state_machine.c:60 sofia/internal/229@tssec.ru Standard DESTROY 2010-06-18 13:28:37.901807 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/229@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@tssec.ru>;tag=beeaf51cf0d364d9 From: <sip:229@tssec.ru>;tag=Be64rve6FSU1D Call-ID: e2bc3098-8a58ff8d@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@10.8.6.6:5080>;tag=fyiai From: "Nikolai Gabelok" <sip:229@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@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@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
Hello, I never used a scenario where a watched phone has call waiting enabled, thus capable of receiving another call. I will try to reproduce this. Ognjen On Thu, Jun 17, 2010 at 2:57 PM, Vladimir Elizarov <xengelpublicx@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
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
I see the same issue with polycom and snom phones (although we don't use snom anymore). There is a bug report open http://jira.freeswitch.org/browse/FSCORE-598. The use of mod_limit works for phones that would normally only want one call at a time anyhow, but that solution does not work for switchboard phones because they may need to grab another incoming call even if they are on a call currently. Travis On Fri, Jun 18, 2010 at 12:53 PM, Ognjen Seslija <oseslija@gmail.com> wrote:
Hello,
I never used a scenario where a watched phone has call waiting enabled, thus capable of receiving another call. I will try to reproduce this.
Ognjen
On Thu, Jun 17, 2010 at 2:57 PM, Vladimir Elizarov < xengelpublicx@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
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
no there isn't that issue has been closed... On Fri, Jun 18, 2010 at 1:22 PM, Travis Kemen <kemen04@gmail.com> wrote:
I see the same issue with polycom and snom phones (although we don't use snom anymore). There is a bug report open http://jira.freeswitch.org/browse/FSCORE-598. The use of mod_limit works for phones that would normally only want one call at a time anyhow, but that solution does not work for switchboard phones because they may need to grab another incoming call even if they are on a call currently.
Travis
On Fri, Jun 18, 2010 at 12:53 PM, Ognjen Seslija <oseslija@gmail.com>wrote:
Hello,
I never used a scenario where a watched phone has call waiting enabled, thus capable of receiving another call. I will try to reproduce this.
Ognjen
On Thu, Jun 17, 2010 at 2:57 PM, Vladimir Elizarov < xengelpublicx@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
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ Twitter: http://twitter.com/FreeSWITCH_wire AIM: anthm MSN:anthony_minessale@hotmail.com <MSN%3Aanthony_minessale@hotmail.com> GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com<PAYPAL%3Aanthony.minessale@gmail.com> IRC: irc.freenode.net #freeswitch FreeSWITCH Developer Conference sip:888@conference.freeswitch.org <sip%3A888@conference.freeswitch.org> googletalk:conf+888@conference.freeswitch.org<googletalk%3Aconf%2B888@conference.freeswitch.org> pstn:+19193869900
participants (4)
-
Anthony Minessale
-
Ognjen Seslija
-
Travis Kemen
-
Vladimir Elizarov