Hi List I'm having problems when a calling extension hangs up before called extension answers. Called extension keeps ringing for quite a while after calling party hangs up, giving called party plenty of time to pick up and listen to dead audio. Here's the set-up Ext 1000 ---- | |---- NAT Router ----- FS on Public IP | Ext 1002 ---- Both Extensions are on same LAN behind same NAT router, using different SIP ports: Ext 1000: 41000 Ext 1002: 41002 FreeSwitch is installed from GIT and conf files are basically unchanged, except IPs. I've pasted a complete trace of transaction below, but I think of relevance is that FreeSwitch receives 5 CANCEL packets from Ext 1000 over a 7 second period before it decides to send the CANCEL on to ext 1002. Seven seconds is a long time for a phone to be ringing. Any ideas on what / where to tweak to get FreeSwitch to respond after first CANCEL would be appreciated. Thanks in advance John Complete trace of transaction follows: freeswitch@internal> recv 993 bytes from udp/[95.xxx.yyy.231]:41000 at 19:01:03.892139: ------------------------------------------------------------------------ INVITE sip:1002@93.aaa.bbb.186 SIP/2.0 Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-141b2a92 From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186> Remote-Party-ID: "1000" <sip:1000@93.aaa.bbb.186>;screen=yes;party=calling Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 101 INVITE Max-Forwards: 70 Contact: "1000" <sip:1000@95.xxx.yyy.231:41000> Expires: 240 User-Agent: Linksys/SPA941-5.1.8 Content-Length: 399 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: replaces Content-Type: application/sdp v=0 o=- 423343 423343 IN IP4 95.xxx.yyy.231 s=- c=IN IP4 95.xxx.yyy.231 t=0 0 m=audio 16384 RTP/AVP 0 2 4 8 18 96 97 98 101 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:8 PCMA/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:30 a=sendrecv ------------------------------------------------------------------------ send 318 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:03.892641: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-141b2a92 From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186> Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 101 INVITE User-Agent: FreeSWITCH-mod_sofia/1.0.head-git- Content-Length: 0 ------------------------------------------------------------------------ 2010-08-11 21:01:03.892755 [DEBUG] sofia.c:6000 IP 95.xxx.yyy.231 Rejected by acl "domains". Falling back to Digest auth. send 805 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:03.901957: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-141b2a92 From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=mr2Kt3U0cB2FF Call-ID: 97c7aad1-f86f1391@192.168.1.34 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="93.aaa.bbb.186", nonce="ca0e3c26-a57a-11df-8498-6130e0d7e4c0", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ recv 401 bytes from udp/[95.xxx.yyy.231]:41000 at 19:01:03.981956: ------------------------------------------------------------------------ ACK sip:1002@93.aaa.bbb.186 SIP/2.0 Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-141b2a92 From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=mr2Kt3U0cB2FF Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 101 ACK Max-Forwards: 70 Contact: "1000" <sip:1000@95.xxx.yyy.231:41000> User-Agent: Linksys/SPA941-5.1.8 Content-Length: 0 ------------------------------------------------------------------------ recv 1229 bytes from udp/[95.xxx.yyy.231]:41000 at 19:01:04.018603: ------------------------------------------------------------------------ INVITE sip:1002@93.aaa.bbb.186 SIP/2.0 Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186> Remote-Party-ID: "1000" <sip:1000@93.aaa.bbb.186>;screen=yes;party=calling Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE Max-Forwards: 70 Proxy-Authorization: Digest username="1000",realm="93.aaa.bbb.186",nonce="ca0e3c26-a57a-11df-8498-6130e0d7e4c0",uri="sip:1002@93.aaa.bbb.186",algorithm=MD5,response="100a38311f3ee9f12c5fb78e61fdf14d",qop=auth,nc=00000001,cnonce="54f72ed1" Contact: "1000" <sip:1000@95.xxx.yyy.231:41000> Expires: 240 User-Agent: Linksys/SPA941-5.1.8 Content-Length: 399 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: replaces Content-Type: application/sdp v=0 o=- 423343 423343 IN IP4 95.xxx.yyy.231 s=- c=IN IP4 95.xxx.yyy.231 t=0 0 m=audio 16384 RTP/AVP 0 2 4 8 18 96 97 98 101 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:8 PCMA/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:30 a=sendrecv ------------------------------------------------------------------------ send 318 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:04.019014: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186> Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE User-Agent: FreeSWITCH-mod_sofia/1.0.head-git- Content-Length: 0 ------------------------------------------------------------------------ 2010-08-11 21:01:04.018556 [DEBUG] sofia.c:6000 IP 95.xxx.yyy.231 Rejected by acl "domains". Falling back to Digest auth. 2010-08-11 21:01:04.021204 [NOTICE] switch_channel.c:779 New Channel sofia/internal/1000@93.aaa.bbb.186 [ca21d98e-a57a-11df-8499-6130e0d7e4c0] 2010-08-11 21:01:04.022284 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000@93.aaa.bbb.186) Running State Change CS_NEW 2010-08-11 21:01:04.022284 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/1000@93.aaa.bbb.186) State NEW 2010-08-11 21:01:04.023433 [DEBUG] sofia.c:4318 Channel sofia/internal/1000@93.aaa.bbb.186 entering state [received][100] 2010-08-11 21:01:04.023433 [DEBUG] sofia.c:4329 Remote SDP: v=0 o=- 423343 423343 IN IP4 95.xxx.yyy.231 s=- c=IN IP4 95.xxx.yyy.231 t=0 0 m=audio 16384 RTP/AVP 0 2 4 8 18 96 97 98 101 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:8 PCMA/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:30 2010-08-11 21:01:04.023433 [DEBUG] sofia_glue.c:3847 Audio Codec Compare [PCMU:0:8000:30]/[G729:18:8000:20] 2010-08-11 21:01:04.023433 [DEBUG] sofia_glue.c:3847 Audio Codec Compare [PCMU:0:8000:30]/[GSM:3:8000:20] 2010-08-11 21:01:04.023433 [DEBUG] sofia_glue.c:3847 Audio Codec Compare [PCMU:0:8000:30]/[G7221:115:32000:20] 2010-08-11 21:01:04.023433 [DEBUG] sofia_glue.c:3847 Audio Codec Compare [PCMU:0:8000:30]/[G7221:107:16000:20] 2010-08-11 21:01:04.023433 [DEBUG] sofia_glue.c:3847 Audio Codec Compare [PCMU:0:8000:30]/[G722:9:8000:20] 2010-08-11 21:01:04.023433 [DEBUG] sofia_glue.c:3847 Audio Codec Compare [PCMU:0:8000:30]/[PCMU:0:8000:20] 2010-08-11 21:01:04.023433 [DEBUG] sofia_glue.c:3847 Audio Codec Compare [PCMU:0:8000:30]/[PCMA:8:8000:20] 2010-08-11 21:01:04.023433 [DEBUG] sofia_glue.c:3895 Substituting codec PCMU@30i@8000h 2010-08-11 21:01:04.023433 [DEBUG] sofia_glue.c:2444 Set Codec sofia/internal/1000@93.aaa.bbb.186 PCMU/8000 30 ms 240 samples 2010-08-11 21:01:04.023433 [DEBUG] sofia_glue.c:3943 Set 2833 dtmf send/recv payload to 101 2010-08-11 21:01:04.023433 [DEBUG] sofia.c:4476 (sofia/internal/1000@93.aaa.bbb.186) State Change CS_NEW -> CS_INIT 2010-08-11 21:01:04.023433 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/1000@93.aaa.bbb.186 [BREAK] 2010-08-11 21:01:04.024600 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000@93.aaa.bbb.186) Running State Change CS_INIT 2010-08-11 21:01:04.024600 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/1000@93.aaa.bbb.186) State INIT 2010-08-11 21:01:04.024600 [DEBUG] mod_sofia.c:83 sofia/internal/1000@93.aaa.bbb.186 SOFIA INIT 2010-08-11 21:01:04.024600 [DEBUG] mod_sofia.c:119 (sofia/internal/1000@93.aaa.bbb.186) State Change CS_INIT -> CS_ROUTING 2010-08-11 21:01:04.024600 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/1000@93.aaa.bbb.186 [BREAK] 2010-08-11 21:01:04.024600 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/1000@93.aaa.bbb.186) State INIT going to sleep 2010-08-11 21:01:04.024600 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000@93.aaa.bbb.186) Running State Change CS_ROUTING 2010-08-11 21:01:04.024600 [DEBUG] switch_channel.c:1512 (sofia/internal/1000@93.aaa.bbb.186) Callstate Change DOWN -> RINGING 2010-08-11 21:01:04.024600 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/1000@93.aaa.bbb.186) State ROUTING 2010-08-11 21:01:04.024600 [DEBUG] mod_sofia.c:142 sofia/internal/1000@93.aaa.bbb.186 SOFIA ROUTING 2010-08-11 21:01:04.024600 [DEBUG] switch_core_state_machine.c:77 sofia/internal/1000@93.aaa.bbb.186 Standard ROUTING 2010-08-11 21:01:04.024600 [INFO] mod_dialplan_xml.c:331 Processing 1000->1002 in context default Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->unloop] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->tod_example] continue=true Dialplan: sofia/internal/1000@93.aaa.bbb.186 Date/Time Match (FAIL) [tod_example] break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->holiday_example] continue=true Dialplan: sofia/internal/1000@93.aaa.bbb.186 Date/Time Match (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [global-intercept] destination_number(1002) =~ /^886$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [group-intercept] destination_number(1002) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [intercept-ext] destination_number(1002) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->redial] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [redial] destination_number(1002) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->global] continue=true Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [global] ${sip_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/internal/1000@93.aaa.bbb.186 Absolute Condition [global] Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [snom-demo-2] destination_number(1002) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [snom-demo-1] destination_number(1002) =~ /^9000$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [eavesdrop] destination_number(1002) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [eavesdrop] destination_number(1002) =~ /^779$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->call_return] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [call_return] destination_number(1002) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->del-group] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [del-group] destination_number(1002) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->add-group] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [add-group] destination_number(1002) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [call-group-simo] destination_number(1002) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [call-group-order] destination_number(1002) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (FAIL) [extension-intercom] destination_number(1002) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Regex (PASS) [Local_Extension] destination_number(1002) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action set(dialed_extension=1002) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action export(dialed_extension=1002) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action set(ringback=${us-ring}) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action set(call_timeout=30) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action set(hangup_after_bridge=true) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action set(continue_on_fail=true) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action answer() Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action sleep(1000) Dialplan: sofia/internal/1000@93.aaa.bbb.186 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension}) 2010-08-11 21:01:04.025632 [DEBUG] switch_core_state_machine.c:119 (sofia/internal/1000@93.aaa.bbb.186) State Change CS_ROUTING -> CS_EXECUTE 2010-08-11 21:01:04.025632 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/1000@93.aaa.bbb.186 [BREAK] 2010-08-11 21:01:04.025632 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/1000@93.aaa.bbb.186) State ROUTING going to sleep 2010-08-11 21:01:04.025632 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000@93.aaa.bbb.186) Running State Change CS_EXECUTE 2010-08-11 21:01:04.025632 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/1000@93.aaa.bbb.186) State EXECUTE 2010-08-11 21:01:04.025632 [DEBUG] mod_sofia.c:235 sofia/internal/1000@93.aaa.bbb.186 SOFIA EXECUTE 2010-08-11 21:01:04.025632 [DEBUG] switch_core_state_machine.c:157 sofia/internal/1000@93.aaa.bbb.186 Standard EXECUTE EXECUTE sofia/internal/1000@93.aaa.bbb.186 hash(insert/93.aaa.bbb.186-spymap/1000/ca21d98e-a57a-11df-8499-6130e0d7e4c0) EXECUTE sofia/internal/1000@93.aaa.bbb.186 hash(insert/93.aaa.bbb.186-last_dial/1000/1002) EXECUTE sofia/internal/1000@93.aaa.bbb.186 hash(insert/93.aaa.bbb.186-last_dial/global/ca21d98e-a57a-11df-8499-6130e0d7e4c0) EXECUTE sofia/internal/1000@93.aaa.bbb.186 set(dialed_extension=1002) 2010-08-11 21:01:04.026839 [DEBUG] mod_dptools.c:854 sofia/internal/1000@93.aaa.bbb.186 SET [dialed_extension]=[1002] EXECUTE sofia/internal/1000@93.aaa.bbb.186 export(dialed_extension=1002) 2010-08-11 21:01:04.026839 [DEBUG] mod_dptools.c:938 EXPORT [dialed_extension]=[1002] EXECUTE sofia/internal/1000@93.aaa.bbb.186 bind_meta_app(1 b s execute_extension::dx XML features) 2010-08-11 21:01:04.027981 [INFO] switch_ivr_async.c:2464 Bound B-Leg: *1 execute_extension::dx XML features EXECUTE sofia/internal/1000@93.aaa.bbb.186 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1000.2010-08-11-21-01-04.wav) 2010-08-11 21:01:04.027981 [INFO] switch_ivr_async.c:2464 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1000.2010-08-11-21-01-04.wav EXECUTE sofia/internal/1000@93.aaa.bbb.186 bind_meta_app(3 b s execute_extension::cf XML features) 2010-08-11 21:01:04.027981 [INFO] switch_ivr_async.c:2464 Bound B-Leg: *3 execute_extension::cf XML features EXECUTE sofia/internal/1000@93.aaa.bbb.186 set(ringback=%(2000,4000,440.0,480.0)) 2010-08-11 21:01:04.027981 [DEBUG] mod_dptools.c:854 sofia/internal/1000@93.aaa.bbb.186 SET [ringback]=[%(2000,4000,440.0,480.0)] EXECUTE sofia/internal/1000@93.aaa.bbb.186 set(transfer_ringback=local_stream://moh) 2010-08-11 21:01:04.029110 [DEBUG] mod_dptools.c:854 sofia/internal/1000@93.aaa.bbb.186 SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/1000@93.aaa.bbb.186 set(call_timeout=30) 2010-08-11 21:01:04.029110 [DEBUG] mod_dptools.c:854 sofia/internal/1000@93.aaa.bbb.186 SET [call_timeout]=[30] EXECUTE sofia/internal/1000@93.aaa.bbb.186 set(hangup_after_bridge=true) 2010-08-11 21:01:04.029110 [DEBUG] mod_dptools.c:854 sofia/internal/1000@93.aaa.bbb.186 SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/1000@93.aaa.bbb.186 set(continue_on_fail=true) 2010-08-11 21:01:04.029110 [DEBUG] mod_dptools.c:854 sofia/internal/1000@93.aaa.bbb.186 SET [continue_on_fail]=[true] EXECUTE sofia/internal/1000@93.aaa.bbb.186 hash(insert/93.aaa.bbb.186-call_return/1002/1000) EXECUTE sofia/internal/1000@93.aaa.bbb.186 hash(insert/93.aaa.bbb.186-last_dial_ext/1002/ca21d98e-a57a-11df-8499-6130e0d7e4c0) EXECUTE sofia/internal/1000@93.aaa.bbb.186 set(called_party_callgroup=techsupport) 2010-08-11 21:01:04.030434 [DEBUG] mod_dptools.c:854 sofia/internal/1000@93.aaa.bbb.186 SET [called_party_callgroup]=[techsupport] EXECUTE sofia/internal/1000@93.aaa.bbb.186 hash(insert/93.aaa.bbb.186-last_dial/techsupport/ca21d98e-a57a-11df-8499-6130e0d7e4c0) EXECUTE sofia/internal/1000@93.aaa.bbb.186 bridge(user/1002@93.aaa.bbb.186) 2010-08-11 21:01:04.032457 [DEBUG] switch_ivr_originate.c:1979 variable string 0 = [presence_id=1002@93.aaa.bbb.186] 2010-08-11 21:01:04.033462 [NOTICE] switch_channel.c:779 New Channel sofia/internal/sip:1002@95.xxx.yyy.231:41002 [ca23b600-a57a-11df-849a-6130e0d7e4c0] 2010-08-11 21:01:04.040579 [DEBUG] mod_sofia.c:3892 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State Change CS_NEW -> CS_INIT 2010-08-11 21:01:04.040579 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/sip:1002@95.xxx.yyy.231:41002 [BREAK] 2010-08-11 21:01:04.040579 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) Running State Change CS_INIT 2010-08-11 21:01:04.041592 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State INIT 2010-08-11 21:01:04.041592 [DEBUG] mod_sofia.c:83 sofia/internal/sip:1002@95.xxx.yyy.231:41002 SOFIA INIT 2010-08-11 21:01:04.041592 [DEBUG] mod_sofia.c:119 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State Change CS_INIT -> CS_ROUTING 2010-08-11 21:01:04.041592 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/sip:1002@95.xxx.yyy.231:41002 [BREAK] 2010-08-11 21:01:04.041592 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State INIT going to sleep 2010-08-11 21:01:04.041592 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) Running State Change CS_ROUTING 2010-08-11 21:01:04.041592 [DEBUG] switch_channel.c:1512 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) Callstate Change DOWN -> RINGING 2010-08-11 21:01:04.041592 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State ROUTING 2010-08-11 21:01:04.041592 [DEBUG] mod_sofia.c:142 sofia/internal/sip:1002@95.xxx.yyy.231:41002 SOFIA ROUTING 2010-08-11 21:01:04.041592 [DEBUG] switch_ivr_originate.c:66 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2010-08-11 21:01:04.041592 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/sip:1002@95.xxx.yyy.231:41002 [BREAK] 2010-08-11 21:01:04.041592 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State ROUTING going to sleep 2010-08-11 21:01:04.041592 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) Running State Change CS_CONSUME_MEDIA 2010-08-11 21:01:04.041592 [DEBUG] switch_core_state_machine.c:360 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State CONSUME_MEDIA 2010-08-11 21:01:04.041592 [DEBUG] switch_core_state_machine.c:360 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State CONSUME_MEDIA going to sleep send 1219 bytes to udp/[95.xxx.yyy.231]:41002 at 19:01:04.042665: ------------------------------------------------------------------------ INVITE sip:1002@95.xxx.yyy.231:41002 SIP/2.0 Via: SIP/2.0/UDP 93.aaa.bbb.186;rport;branch=z9hG4bKyvX4D3Z0yHZ5e Max-Forwards: 69 From: "Extension 1000" <sip:1000@93.aaa.bbb.186>;tag=paN5XSX76veNp To: <sip:1002@95.xxx.yyy.231:41002> Call-ID: a1834f63-201d-122e-719b-a4badbdfa48e CSeq: 440568 INVITE Contact: <sip:mod_sofia@93.aaa.bbb.186: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: 318 X-FS-Support: update_display Remote-Party-ID: "Extension 1000" <sip:1000@93.aaa.bbb.186>;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1281531490 1281531491 IN IP4 93.aaa.bbb.186 s=FreeSWITCH c=IN IP4 93.aaa.bbb.186 t=0 0 m=audio 21774 RTP/AVP 0 18 9 8 101 13 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=rtpmap:9 G722/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:30 ------------------------------------------------------------------------ 2010-08-11 21:01:04.041592 [DEBUG] sofia.c:4318 Channel sofia/internal/sip:1002@95.xxx.yyy.231:41002 entering state [calling][0] recv 301 bytes from udp/[95.xxx.yyy.231]:41002 at 19:01:04.120370: ------------------------------------------------------------------------ SIP/2.0 100 Trying To: <sip:1002@95.xxx.yyy.231:41002> From: "Extension 1000" <sip:1000@93.aaa.bbb.186>;tag=paN5XSX76veNp Call-ID: a1834f63-201d-122e-719b-a4badbdfa48e CSeq: 440568 INVITE Via: SIP/2.0/UDP 93.aaa.bbb.186;branch=z9hG4bKyvX4D3Z0yHZ5e Server: Linksys/SPA941-5.1.8 Content-Length: 0 ------------------------------------------------------------------------ recv 397 bytes from udp/[95.xxx.yyy.231]:41002 at 19:01:04.264793: ------------------------------------------------------------------------ SIP/2.0 180 Ringing To: <sip:1002@95.xxx.yyy.231:41002>;tag=dd77407622bd885i0 From: "Extension 1000" <sip:1000@93.aaa.bbb.186>;tag=paN5XSX76veNp Call-ID: a1834f63-201d-122e-719b-a4badbdfa48e CSeq: 440568 INVITE Via: SIP/2.0/UDP 93.aaa.bbb.186;branch=z9hG4bKyvX4D3Z0yHZ5e Server: Linksys/SPA941-5.1.8 Remote-Party-ID: "1002" <sip:1002@93.aaa.bbb.186>;screen=yes;party=called Content-Length: 0 ------------------------------------------------------------------------ 2010-08-11 21:01:04.264258 [INFO] sofia.c:662 sofia/internal/sip:1002@95.xxx.yyy.231:41002 Update Callee ID to "1002" <1002> 2010-08-11 21:01:04.273760 [DEBUG] sofia.c:4318 Channel sofia/internal/sip:1002@95.xxx.yyy.231:41002 entering state [proceeding][180] 2010-08-11 21:01:04.273760 [NOTICE] sofia.c:4390 Ring-Ready sofia/internal/sip:1002@95.xxx.yyy.231:41002! 2010-08-11 21:01:04.276790 [INFO] switch_ivr_originate.c:1079 Sending early media 2010-08-11 21:01:04.276790 [DEBUG] sofia_glue.c:2684 AUDIO RTP [sofia/internal/1000@93.aaa.bbb.186] 93.aaa.bbb.186 port 29380 -> 95.xxx.yyy.231 port 16384 codec: 0 ms: 30 2010-08-11 21:01:04.276790 [DEBUG] switch_rtp.c:1413 Starting timer [soft] 240 bytes per 30ms 2010-08-11 21:01:04.278977 [DEBUG] sofia_glue.c:2894 Set 2833 dtmf send payload to 101 2010-08-11 21:01:04.278977 [DEBUG] sofia_glue.c:2899 Set 2833 dtmf receive payload to 101 2010-08-11 21:01:04.278977 [DEBUG] mod_sofia.c:2144 Ring SDP: v=0 o=FreeSWITCH 1281523884 1281523885 IN IP4 93.aaa.bbb.186 s=FreeSWITCH c=IN IP4 93.aaa.bbb.186 t=0 0 m=audio 29380 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:30 a=sendrecv 2010-08-11 21:01:04.278977 [NOTICE] mod_sofia.c:2147 Pre-Answer sofia/internal/1000@93.aaa.bbb.186! 2010-08-11 21:01:04.278977 [DEBUG] switch_channel.c:2397 (sofia/internal/1000@93.aaa.bbb.186) Callstate Change RINGING -> EARLY 2010-08-11 21:01:04.278977 [DEBUG] switch_core_session.c:658 Send signal sofia/internal/1000@93.aaa.bbb.186 [BREAK] 2010-08-11 21:01:04.278977 [DEBUG] switch_ivr_originate.c:1128 Raw Codec Activation Success L16@8000hz 1 channel 30ms 2010-08-11 21:01:04.278977 [DEBUG] switch_core_codec.c:116 sofia/internal/1000@93.aaa.bbb.186 Push codec L16:10 2010-08-11 21:01:04.278977 [DEBUG] switch_ivr_originate.c:1193 Play Ringback Tone [%(2000,4000,440.0,480.0)] send 1118 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:04.279808: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=N1Ucvyc49Kr2a Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE Contact: <sip:1002@93.aaa.bbb.186: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: 247 Remote-Party-ID: "1002" <sip:1002@93.aaa.bbb.186>;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1281523884 1281523885 IN IP4 93.aaa.bbb.186 s=FreeSWITCH c=IN IP4 93.aaa.bbb.186 t=0 0 m=audio 29380 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:30 ------------------------------------------------------------------------ 2010-08-11 21:01:04.280443 [DEBUG] sofia.c:4313 Channel sofia/internal/1000@93.aaa.bbb.186 skipping state [early][183] 2010-08-11 21:01:04.405197 [DEBUG] switch_rtp.c:2527 Correct ip/port confirmed. recv 578 bytes from udp/[95.xxx.yyy.231]:41000 at 19:01:07.276699: ------------------------------------------------------------------------ CANCEL sip:1002@93.aaa.bbb.186 SIP/2.0 Via: SIP/2.0/UDP 95.xxx.yyy.231:4100000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186> Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 CANCEL Max-Forwards: 70 Proxy-Authorization: Digest username="1000",realm="93.aaa.bbb.186",nonce="ca0e3c26-a57a-11df-8498-6130e0d7e4c0",uri="sip:1002@93.aaa.bbb.186",algorithm=MD5,response="314faae6a65e754939bf9f5678a2fd60",qop=auth,nc=00000002,cnonce="54f72ed1" User-Agent: Linksys/SPA941-5.1.8 Content-Length: 0 ------------------------------------------------------------------------ recv 578 bytes from udp/[95.xxx.yyy.231]:41000 at 19:01:07.764599: ------------------------------------------------------------------------ CANCEL sip:1002@93.aaa.bbb.186 SIP/2.0 Via: SIP/2.0/UDP 95.xxx.yyy.231:4100000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186> Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 CANCEL Max-Forwards: 70 Proxy-Authorization: Digest username="1000",realm="93.aaa.bbb.186",nonce="ca0e3c26-a57a-11df-8498-6130e0d7e4c0",uri="sip:1002@93.aaa.bbb.186",algorithm=MD5,response="314faae6a65e754939bf9f5678a2fd60",qop=auth,nc=00000002,cnonce="54f72ed1" User-Agent: Linksys/SPA941-5.1.8 Content-Length: 0 ------------------------------------------------------------------------ recv 578 bytes from udp/[95.xxx.yyy.231]:41000 at 19:01:08.765910: ------------------------------------------------------------------------ CANCEL sip:1002@93.aaa.bbb.186 SIP/2.0 Via: SIP/2.0/UDP 95.xxx.yyy.231:4100000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186> Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 CANCEL Max-Forwards: 70 Proxy-Authorization: Digest username="1000",realm="93.aaa.bbb.186",nonce="ca0e3c26-a57a-11df-8498-6130e0d7e4c0",uri="sip:1002@93.aaa.bbb.186",algorithm=MD5,response="314faae6a65e754939bf9f5678a2fd60",qop=auth,nc=00000002,cnonce="54f72ed1" User-Agent: Linksys/SPA941-5.1.8 Content-Length: 0 ------------------------------------------------------------------------ recv 578 bytes from udp/[95.xxx.yyy.231]:41000 at 19:01:10.764272: ------------------------------------------------------------------------ CANCEL sip:1002@93.aaa.bbb.186 SIP/2.0 Via: SIP/2.0/UDP 95.xxx.yyy.231:4100000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186> Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 CANCEL Max-Forwards: 70 Proxy-Authorization: Digest username="1000",realm="93.aaa.bbb.186",nonce="ca0e3c26-a57a-11df-8498-6130e0d7e4c0",uri="sip:1002@93.aaa.bbb.186",algorithm=MD5,response="314faae6a65e754939bf9f5678a2fd60",qop=auth,nc=00000002,cnonce="54f72ed1" User-Agent: Linksys/SPA941-5.1.8 Content-Length: 0 ------------------------------------------------------------------------ recv 576 bytes from udp/[95.xxx.yyy.231]:41000 at 19:01:14.762786: ------------------------------------------------------------------------ CANCEL sip:1002@93.aaa.bbb.186 SIP/2.0 Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186> Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 CANCEL Max-Forwards: 70 Proxy-Authorization: Digest username="1000",realm="93.aaa.bbb.186",nonce="ca0e3c26-a57a-11df-8498-6130e0d7e4c0",uri="sip:1002@93.aaa.bbb.186",algorithm=MD5,response="314faae6a65e754939bf9f5678a2fd60",qop=auth,nc=00000002,cnonce="54f72ed1" User-Agent: Linksys/SPA941-5.1.8 Content-Length: 0 ------------------------------------------------------------------------ send 284 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:14.763018: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=N1Ucvyc49Kr2a Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 CANCEL Content-Length: 0 ------------------------------------------------------------------------ send 647 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:14.763162: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=N1Ucvyc49Kr2a Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE 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-Length: 0 ------------------------------------------------------------------------ 2010-08-11 21:01:14.762892 [DEBUG] sofia.c:4318 Channel sofia/internal/1000@93.aaa.bbb.186 entering state [terminated][487] 2010-08-11 21:01:14.762892 [DEBUG] switch_channel.c:2309 (sofia/internal/1000@93.aaa.bbb.186) Callstate Change EARLY -> HANGUP 2010-08-11 21:01:14.762892 [NOTICE] sofia.c:4932 Hangup sofia/internal/1000@93.aaa.bbb.186 [CS_EXECUTE] [ORIGINATOR_CANCEL] 2010-08-11 21:01:14.762892 [DEBUG] switch_channel.c:2325 Send signal sofia/internal/1000@93.aaa.bbb.186 [KILL] 2010-08-11 21:01:14.762892 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/1000@93.aaa.bbb.186 [BREAK] 2010-08-11 21:01:14.785078 [DEBUG] switch_core_codec.c:140 sofia/internal/1000@93.aaa.bbb.186 Restore previous codec PCMU:0. 2010-08-11 21:01:14.785078 [DEBUG] switch_channel.c:2309 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) Callstate Change RINGING -> HANGUP 2010-08-11 21:01:14.785078 [NOTICE] switch_ivr_originate.c:3282 Hangup sofia/internal/sip:1002@95.xxx.yyy.231:41002 [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL] 2010-08-11 21:01:14.785078 [DEBUG] switch_channel.c:2325 Send signal sofia/internal/sip:1002@95.xxx.yyy.231:41002 [KILL] 2010-08-11 21:01:14.785078 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/sip:1002@95.xxx.yyy.231:41002 [BREAK] 2010-08-11 21:01:14.785078 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) Running State Change CS_HANGUP 2010-08-11 21:01:14.785078 [DEBUG] switch_ivr_originate.c:3425 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL] 2010-08-11 21:01:14.785078 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State HANGUP 2010-08-11 21:01:14.785078 [DEBUG] mod_sofia.c:447 sofia/internal/sip:1002@95.xxx.yyy.231:41002 Overriding SIP cause 487 with 487 from the other leg 2010-08-11 21:01:14.785078 [DEBUG] mod_sofia.c:453 Channel sofia/internal/sip:1002@95.xxx.yyy.231:41002 hanging up, cause: ORIGINATOR_CANCEL 2010-08-11 21:01:14.785078 [ERR] switch_ivr_originate.c:2623 Cannot create outgoing channel of type [user] cause: [ORIGINATOR_CANCEL] 2010-08-11 21:01:14.785078 [DEBUG] switch_ivr_originate.c:3431 Originate Resulted in Error Cause: 487 [ORIGINATOR_CANCEL] 2010-08-11 21:01:14.785078 [INFO] mod_dptools.c:2393 Originate Failed. Cause: ORIGINATOR_CANCEL 2010-08-11 21:01:14.788208 [DEBUG] switch_core_session.c:1905 sofia/internal/1000@93.aaa.bbb.186 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2010-08-11 21:01:14.788208 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/1000@93.aaa.bbb.186) State EXECUTE going to sleep 2010-08-11 21:01:14.788208 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000@93.aaa.bbb.186) Running State Change CS_HANGUP 2010-08-11 21:01:14.788208 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/1000@93.aaa.bbb.186) State HANGUP 2010-08-11 21:01:14.788208 [DEBUG] mod_sofia.c:447 sofia/internal/1000@93.aaa.bbb.186 Overriding SIP cause 487 with 487 from the other leg 2010-08-11 21:01:14.788208 [DEBUG] mod_sofia.c:453 Channel sofia/internal/1000@93.aaa.bbb.186 hanging up, cause: ORIGINATOR_CANCEL 2010-08-11 21:01:14.797311 [DEBUG] mod_sofia.c:506 Sending CANCEL to sofia/internal/sip:1002@95.xxx.yyy.231:41002 2010-08-11 21:01:14.797311 [DEBUG] switch_core_state_machine.c:46 sofia/internal/sip:1002@95.xxx.yyy.231:41002 Standard HANGUP, cause: ORIGINATOR_CANCEL 2010-08-11 21:01:14.797311 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State HANGUP going to sleep 2010-08-11 21:01:14.797311 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State Change CS_HANGUP -> CS_REPORTING 2010-08-11 21:01:14.797311 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/sip:1002@95.xxx.yyy.231:41002 [BREAK] 2010-08-11 21:01:14.797311 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) Running State Change CS_REPORTING 2010-08-11 21:01:14.797311 [DEBUG] switch_core_state_machine.c:595 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State REPORTING 2010-08-11 21:01:14.797311 [DEBUG] switch_core_state_machine.c:53 sofia/internal/sip:1002@95.xxx.yyy.231:41002 Standard REPORTING, cause: ORIGINATOR_CANCEL 2010-08-11 21:01:14.797311 [DEBUG] switch_core_state_machine.c:595 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State REPORTING going to sleep 2010-08-11 21:01:14.797311 [DEBUG] switch_core_state_machine.c:327 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State Change CS_REPORTING -> CS_DESTROY 2010-08-11 21:01:14.797311 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/sip:1002@95.xxx.yyy.231:41002 [BREAK] 2010-08-11 21:01:14.797311 [DEBUG] switch_core_session.c:1202 Session 16 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) Locked, Waiting on external entities 2010-08-11 21:01:14.797311 [NOTICE] switch_core_session.c:1220 Session 16 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) Ended 2010-08-11 21:01:14.797311 [NOTICE] switch_core_session.c:1222 Close Channel sofia/internal/sip:1002@95.xxx.yyy.231:41002 [CS_DESTROY] 2010-08-11 21:01:14.797311 [DEBUG] switch_core_state_machine.c:427 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) Callstate Change HANGUP -> DOWN 2010-08-11 21:01:14.797311 [DEBUG] switch_core_state_machine.c:430 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) Running State Change CS_DESTROY 2010-08-11 21:01:14.797311 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State DESTROY 2010-08-11 21:01:14.797311 [DEBUG] mod_sofia.c:358 sofia/internal/sip:1002@95.xxx.yyy.231:41002 SOFIA DESTROY 2010-08-11 21:01:14.797311 [DEBUG] switch_core_state_machine.c:60 sofia/internal/sip:1002@95.xxx.yyy.231:41002 Standard DESTROY 2010-08-11 21:01:14.797311 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/sip:1002@95.xxx.yyy.231:41002) State DESTROY going to sleep send 376 bytes to udp/[95.xxx.yyy.231]:41002 at 19:01:14.798471: ------------------------------------------------------------------------ CANCEL sip:1002@95.xxx.yyy.231:41002 SIP/2.0 Via: SIP/2.0/UDP 93.aaa.bbb.186;rport;branch=z9hG4bKyvX4D3Z0yHZ5e Max-Forwards: 69 From: "Extension 1000" <sip:1000@93.aaa.bbb.186>;tag=paN5XSX76veNp To: <sip:1002@95.xxx.yyy.231:41002> Call-ID: a1834f63-201d-122e-719b-a4badbdfa48e CSeq: 440568 CANCEL Reason: FreeSWITCH;cause=487;text="ORIGINATOR_CANCEL" Content-Length: 0 ------------------------------------------------------------------------ 2010-08-11 21:01:14.801620 [DEBUG] switch_core_state_machine.c:46 sofia/internal/1000@93.aaa.bbb.186 Standard HANGUP, cause: ORIGINATOR_CANCEL 2010-08-11 21:01:14.801620 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/1000@93.aaa.bbb.186) State HANGUP going to sleep 2010-08-11 21:01:14.801620 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/1000@93.aaa.bbb.186) State Change CS_HANGUP -> CS_REPORTING 2010-08-11 21:01:14.801620 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/1000@93.aaa.bbb.186 [BREAK] 2010-08-11 21:01:14.801620 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/1000@93.aaa.bbb.186) Running State Change CS_REPORTING 2010-08-11 21:01:14.801620 [DEBUG] switch_core_state_machine.c:595 (sofia/internal/1000@93.aaa.bbb.186) State REPORTING 2010-08-11 21:01:14.801620 [DEBUG] switch_core_state_machine.c:53 sofia/internal/1000@93.aaa.bbb.186 Standard REPORTING, cause: ORIGINATOR_CANCEL 2010-08-11 21:01:14.801620 [DEBUG] switch_core_state_machine.c:595 (sofia/internal/1000@93.aaa.bbb.186) State REPORTING going to sleep 2010-08-11 21:01:14.801620 [DEBUG] switch_core_state_machine.c:327 (sofia/internal/1000@93.aaa.bbb.186) State Change CS_REPORTING -> CS_DESTROY 2010-08-11 21:01:14.801620 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/1000@93.aaa.bbb.186 [BREAK] 2010-08-11 21:01:14.801620 [DEBUG] switch_core_session.c:1202 Session 15 (sofia/internal/1000@93.aaa.bbb.186) Locked, Waiting on external entities 2010-08-11 21:01:14.801620 [NOTICE] switch_core_session.c:1220 Session 15 (sofia/internal/1000@93.aaa.bbb.186) Ended 2010-08-11 21:01:14.801620 [NOTICE] switch_core_session.c:1222 Close Channel sofia/internal/1000@93.aaa.bbb.186 [CS_DESTROY] 2010-08-11 21:01:14.801620 [DEBUG] switch_core_state_machine.c:427 (sofia/internal/1000@93.aaa.bbb.186) Callstate Change HANGUP -> DOWN 2010-08-11 21:01:14.801620 [DEBUG] switch_core_state_machine.c:430 (sofia/internal/1000@93.aaa.bbb.186) Running State Change CS_DESTROY 2010-08-11 21:01:14.801620 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/1000@93.aaa.bbb.186) State DESTROY 2010-08-11 21:01:14.801620 [DEBUG] mod_sofia.c:358 sofia/internal/1000@93.aaa.bbb.186 SOFIA DESTROY 2010-08-11 21:01:14.801620 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@93.aaa.bbb.186 Standard DESTROY 2010-08-11 21:01:14.801620 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/1000@93.aaa.bbb.186) State DESTROY going to sleep recv 335 bytes from udp/[95.xxx.yyy.231]:41002 at 19:01:14.875581: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated To: <sip:1002@95.xxx.yyy.231:41002>;tag=dd77407622bd885i0 From: "Extension 1000" <sip:1000@93.aaa.bbb.186>;tag=paN5XSX76veNp Call-ID: a1834f63-201d-122e-719b-a4badbdfa48e CSeq: 440568 INVITE Via: SIP/2.0/UDP 93.aaa.bbb.186;branch=z9hG4bKyvX4D3Z0yHZ5e Server: Linksys/SPA941-5.1.8 Content-Length: 0 ------------------------------------------------------------------------ send 337 bytes to udp/[95.xxx.yyy.231]:41002 at 19:01:14.875798: ------------------------------------------------------------------------ ACK sip:1002@95.xxx.yyy.231:41002 SIP/2.0 Via: SIP/2.0/UDP 93.aaa.bbb.186;rport;branch=z9hG4bKyvX4D3Z0yHZ5e Max-Forwards: 69 From: "Extension 1000" <sip:1000@93.aaa.bbb.186>;tag=paN5XSX76veNp To: <sip:1002@95.xxx.yyy.231:41002>;tag=dd77407622bd885i0 Call-ID: a1834f63-201d-122e-719b-a4badbdfa48e CSeq: 440568 ACK Content-Length: 0 ------------------------------------------------------------------------ recv 319 bytes from udp/[95.xxx.yyy.231]:41002 at 19:01:14.887136: ------------------------------------------------------------------------ SIP/2.0 200 OK To: <sip:1002@95.xxx.yyy.231:41002>;tag=dd77407622bd885i0 From: "Extension 1000" <sip:1000@93.aaa.bbb.186>;tag=paN5XSX76veNp Call-ID: a1834f63-201d-122e-719b-a4badbdfa48e CSeq: 440568 CANCEL Via: SIP/2.0/UDP 93.aaa.bbb.186;branch=z9hG4bKyvX4D3Z0yHZ5e Server: Linksys/SPA941-5.1.8 Content-Length: 0 ------------------------------------------------------------------------ send 647 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:15.263994: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=N1Ucvyc49Kr2a Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE 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-Length: 0 ------------------------------------------------------------------------ send 647 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:16.264001: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=N1Ucvyc49Kr2a Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE 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-Length: 0 ------------------------------------------------------------------------ send 647 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:18.264000: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=N1Ucvyc49Kr2a Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE 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-Length: 0 ------------------------------------------------------------------------ send 647 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:22.264012: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=N1Ucvyc49Kr2a Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE 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-Length: 0 ------------------------------------------------------------------------ send 647 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:26.264005: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=N1Ucvyc49Kr2a Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE 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-Length: 0 ------------------------------------------------------------------------ send 647 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:30.264009: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=N1Ucvyc49Kr2a Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE 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-Length: 0 ------------------------------------------------------------------------ recv 331 bytes from udp/[95.xxx.yyy.231]:41002 at 19:01:30.347502: ------------------------------------------------------------------------ NOTIFY sip:93.aaa.bbb.186 SIP/2.0 Via: SIP/2.0/UDP 95.xxx.yyy.231:41002;branch=z9hG4bK-adf19f8b From: "1002" <sip:1002@93.aaa.bbb.186>;tag=6c504ae2eadd96bfo0 To: <sip:93.aaa.bbb.186> Call-ID: bf54057e-64adbcd3@192.168.1.40 CSeq: 70 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA941-5.1.8 Content-Length: 0 ------------------------------------------------------------------------ send 637 bytes to udp/[95.xxx.yyy.231]:41002 at 19:01:30.347847: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 95.xxx.yyy.231:41002;branch=z9hG4bK-adf19f8b From: "1002" <sip:1002@93.aaa.bbb.186>;tag=6c504ae2eadd96bfo0 To: <sip:93.aaa.bbb.186>;tag=QKeyZmeB4547H Call-ID: bf54057e-64adbcd3@192.168.1.40 CSeq: 70 NOTIFY Contact: <sip:93.aaa.bbb.186> 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-Length: 0 ------------------------------------------------------------------------ send 647 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:34.268007: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=N1Ucvyc49Kr2a Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE 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-Length: 0 ------------------------------------------------------------------------ send 647 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:38.268010: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=N1Ucvyc49Kr2a Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE 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-Length: 0 ------------------------------------------------------------------------ recv 331 bytes from udp/[95.xxx.yyy.231]:41000 at 19:01:39.777149: ------------------------------------------------------------------------ NOTIFY sip:93.aaa.bbb.186 SIP/2.0 Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-4494dffc From: "1000" <sip:1000@93.aaa.bbb.186>;tag=9ddc56accbaeed50o0 To: <sip:93.aaa.bbb.186> Call-ID: 8acf935c-c8ed5860@192.168.1.34 CSeq: 71 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/SPA941-5.1.8 Content-Length: 0 ------------------------------------------------------------------------ send 637 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:39.777522: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-4494dffc From: "1000" <sip:1000@93.aaa.bbb.186>;tag=9ddc56accbaeed50o0 To: <sip:93.aaa.bbb.186>;tag=rv7p1FZe1eUtD Call-ID: 8acf935c-c8ed5860@192.168.1.34 CSeq: 71 NOTIFY Contact: <sip:93.aaa.bbb.186> 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-Length: 0 ------------------------------------------------------------------------ send 647 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:42.268669: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=N1Ucvyc49Kr2a Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE 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-Length: 0 ------------------------------------------------------------------------ send 647 bytes to udp/[95.xxx.yyy.231]:41000 at 19:01:46.268661: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 95.xxx.yyy.231:41000;branch=z9hG4bK-bf655f9e From: "1000" <sip:1000@93.aaa.bbb.186>;tag=ae60c1d11550e891o0 To: "Extension 1002" <sip:1002@93.aaa.bbb.186>;tag=N1Ucvyc49Kr2a Call-ID: 97c7aad1-f86f1391@192.168.1.34 CSeq: 102 INVITE 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-Length: 0 ------------------------------------------------------------------------ freeswitch@internal> ...
participants (1)
-
Area Europa