freeswitch@rim> 546 bytes from tcp/[10.1.16.10]:5065 at 00:02:55.713864: ------------------------------------------------------------------------ REFER sip:mod_sofia@10.1.16.1:5060;transport=tcp SIP/2.0 FROM: ;epid=5553A23860;tag=695d86eb9c TO: ;tag=8091rHjK8Q9rj CSEQ: 1 REFER CALL-ID: 326ef4fc-3044-122b-4f8f-0002b335f374 MAX-FORWARDS: 70 VIA: SIP/2.0/TCP 10.1.16.10:5065;branch=z9hG4bKc1c23c79 CONTACT: ;automata CONTENT-LENGTH: 0 REFER-TO: REFERRED-BY: USER-AGENT: RTCC/3.0.0.0 ------------------------------------------------------------------------ send 538 bytes to tcp/[10.1.16.10]:5065 at 00:02:55.715093: ------------------------------------------------------------------------ SIP/2.0 202 Accepted Via: SIP/2.0/TCP 10.1.16.10:5065;branch=z9hG4bKc1c23c79;rport=5065 FROM: ;epid=5553A23860;tag=695d86eb9c TO: ;tag=8091rHjK8Q9rj CALL-ID: 326ef4fc-3044-122b-4f8f-0002b335f374 CSEQ: 1 REFER Contact: User-Agent: FreeSWITCH-1.0.pre3 (7007M)-mod_sofia Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: 100rel, precondition, timer Content-Length: 0 ------------------------------------------------------------------------ 2007-12-28 16:02:55 [DEBUG] sofia.c:178 sofia_event_callback() event [nua_i_refer] status [202][Accepted] session: sofia/default/501@10.1.16.10;transport=tcp 2007-12-28 16:02:55 [DEBUG] sofia.c:1756 sofia_handle_sip_i_refer() Process REFER to [448@10.1.16.1] 2007-12-28 16:02:55 [DEBUG] switch_ivr.c:927 switch_ivr_session_transfer() sofia/default/498@10.1.16.1:5061 State Change CS_EXECUTE -> CS_RING 2007-12-28 16:02:55 [DEBUG] switch_core_session.c:633 switch_core_session_signal_state_change() Kill sofia/default/498@10.1.16.1:5061 [BREAK] 2007-12-28 16:02:55 [DEBUG] switch_core_session.c:350 switch_core_session_receive_message() Kill sofia/default/498@10.1.16.1:5061 [BREAK] 2007-12-28 16:02:55 [NOTICE] switch_ivr.c:933 switch_ivr_session_transfer() Transfer sofia/default/498@10.1.16.1:5061 to XML[448@default] send 743 bytes to tcp/[10.1.16.10]:5065 at 00:02:55.718502: ------------------------------------------------------------------------ NOTIFY sip:dune.domain.local:5065;transport=Tcp;maddr=10.1.16.10;ms-opaque=f448e28078403412 SIP/2.0 Via: SIP/2.0/TCP 10.1.16.1;branch=z9hG4bKe74p2ac6e1v2B Max-Forwards: 70 From: "Ady" ;tag=8091rHjK8Q9rj To: ;transport=tcp;tag=695d86eb9c Call-ID: 326ef4fc-3044-122b-4f8f-0002b335f374 CSeq: 93324942 NOTIFY Contact: User-Agent: FreeSWITCH-1.0.pre3 (7007M)-mod_sofia Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: 100rel, precondition, timer Event: refer;id=1 Subscription-State: terminated;noresource Content-Type: message/sipfrag Content-Length: 14 SIP/2.0 200 OK ------------------------------------------------------------------------ recv 306 bytes from tcp/[10.1.16.10]:5065 at 00:02:55.720402: ------------------------------------------------------------------------ SIP/2.0 200 OK FROM: "Ady";tag=8091rHjK8Q9rj TO: ;tag=695d86eb9c;transport=tcp;epid=5553A23860 CSEQ: 93324942 NOTIFY CALL-ID: 326ef4fc-3044-122b-4f8f-0002b335f374 VIA: SIP/2.0/TCP 10.1.16.1;branch=z9hG4bKe74p2ac6e1v2B CONTENT-LENGTH: 0 SERVER: RTCC/3.0.0.0 ------------------------------------------------------------------------ 2007-12-28 16:02:55 [DEBUG] switch_core_session.c:350 switch_core_session_receive_message() Kill sofia/default/498@10.1.16.1:5061 [BREAK] 2007-12-28 16:02:55 [DEBUG] switch_ivr_bridge.c:224 audio_bridge_thread() Kill sofia/default/501@10.1.16.10;transport=tcp [BREAK] 2007-12-28 16:02:55 [DEBUG] switch_ivr_bridge.c:229 audio_bridge_thread() BRIDGE THREAD DONE [sofia/default/498@10.1.16.1:5061] 2007-12-28 16:02:55 [DEBUG] switch_ivr_bridge.c:669 switch_ivr_multi_threaded_bridge() sofia/default/501@10.1.16.10;transport=tcp State Change CS_LOOPBACK -> CS_RESET 2007-12-28 16:02:55 [DEBUG] switch_core_session.c:633 switch_core_session_signal_state_change() Kill sofia/default/501@10.1.16.10;transport=tcp [BREAK] 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:402 switch_core_session_run() sofia/default/498@10.1.16.1:5061 Running State Change CS_RING 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:417 switch_core_session_run() (sofia/default/498@10.1.16.1:5061) State RING 2007-12-28 16:02:55 [DEBUG] mod_sofia.c:117 sofia_on_ring() sofia/default/498@10.1.16.1:5061 SOFIA RING 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:64 switch_core_standard_on_ring() Standard RING sofia/default/498@10.1.16.1:5061 2007-12-28 16:02:55 [INFO] mod_dialplan_xml.c:217 dialplan_hunt() Processing Ady->448! 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^886$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^([0-9]{3})$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions network_addr(10.1.16.1) =~ /^10.1.16.1$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions network_addr(10.1.16.1) =~ /^10.1.16.10$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /498/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^886(\d+)$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^870$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${network_addr}(10.1.16.1) =~ // 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions ${numbering_plan}() =~ // 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^88(.*)$|^\*0(.*)$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^\*69$|^869$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^80(\d{2})$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^81(\d{2})$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^82(\d{2})$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^83(\d{2})$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^8(10[01][0-9])$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^(10[01][0-9])$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^sip:(.*)$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^(3\d{3})$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^9(888|1616)$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^8792$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^8793$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /5000/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^5900$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^5901$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] switch_core_session.c:350 switch_core_session_receive_message() Kill sofia/default/501@10.1.16.10;transport=tcp [BREAK] 2007-12-28 16:02:55 [DEBUG] switch_ivr_bridge.c:224 audio_bridge_thread() Kill sofia/default/498@10.1.16.1:5061 [BREAK] 2007-12-28 16:02:55 [DEBUG] switch_ivr_bridge.c:229 audio_bridge_thread() BRIDGE THREAD DONE [sofia/default/501@10.1.16.10;transport=tcp] 2007-12-28 16:02:55 [NOTICE] switch_ivr_bridge.c:259 audio_bridge_on_loopback() Hangup sofia/default/501@10.1.16.10;transport=tcp [CS_RESET] [NORMAL_CLEARING] 2007-12-28 16:02:55 [DEBUG] switch_channel.c:1237 switch_channel_perform_hangup() Kill sofia/default/501@10.1.16.10;transport=tcp [KILL] 2007-12-28 16:02:55 [DEBUG] switch_core_session.c:633 switch_core_session_signal_state_change() Kill sofia/default/501@10.1.16.10;transport=tcp [BREAK] 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:402 switch_core_session_run() sofia/default/501@10.1.16.10;transport=tcp Running State Change CS_HANGUP 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:411 switch_core_session_run() (sofia/default/501@10.1.16.10;transport=tcp) State HANGUP 2007-12-28 16:02:55 [DEBUG] mod_sofia.c:287 sofia_on_hangup() Channel sofia/default/501@10.1.16.10;transport=tcp hanging up, cause: NORMAL_CLEARING 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^9999$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:108 parse_exten() Regex mismatch 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:106 parse_exten() test conditions destination_number(448) =~ /^(.*)$/ 2007-12-28 16:02:55 [DEBUG] mod_dialplan_xml.c:273 dialplan_hunt() sofia/default/498@10.1.16.1:5061 State Change CS_RING -> CS_EXECUTE 2007-12-28 16:02:55 [DEBUG] switch_core_session.c:633 switch_core_session_signal_state_change() Kill sofia/default/498@10.1.16.1:5061 [BREAK] 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:402 switch_core_session_run() sofia/default/498@10.1.16.1:5061 Running State Change CS_EXECUTE 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:423 switch_core_session_run() (sofia/default/498@10.1.16.1:5061) State EXECUTE 2007-12-28 16:02:55 [DEBUG] mod_sofia.c:172 sofia_on_execute() sofia/default/498@10.1.16.1:5061 SOFIA EXECUTE 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:121 switch_core_standard_on_execute() Standard EXECUTE 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:135 switch_core_standard_on_execute() Execute set(sip_transport=tcp) 2007-12-28 16:02:55 [DEBUG] mod_dptools.c:453 set_function() SET [sip_transport]=[tcp] 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:135 switch_core_standard_on_execute() Execute set(pass_rfc2833=true) 2007-12-28 16:02:55 [DEBUG] mod_dptools.c:453 set_function() SET [pass_rfc2833]=[true] 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:135 switch_core_standard_on_execute() Execute bridge(sofia/default/${destination_number}@10.1.16.10;transport=tcp) 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:159 switch_core_standard_on_execute() Expanded String bridge(sofia/default/448@10.1.16.10;transport=tcp) 2007-12-28 16:02:55 [NOTICE] switch_channel.c:438 switch_channel_set_name() New Chan sofia/default/448@10.1.16.10;transport=tcp [41bbac69-b733-465b-a107-95a8459d0e1b] 2007-12-28 16:02:55 [DEBUG] mod_sofia.c:1695 sofia_outgoing_channel() sofia/default/448@10.1.16.10;transport=tcp State Change CS_NEW -> CS_INIT 2007-12-28 16:02:55 [DEBUG] switch_core_session.c:633 switch_core_session_signal_state_change() Kill sofia/default/448@10.1.16.10;transport=tcp [BREAK] recv 340 bytes from tcp/[10.1.16.10]:5065 at 00:02:55.767229: ------------------------------------------------------------------------ BYE sip:mod_sofia@10.1.16.1:5060;transport=tcp SIP/2.0 FROM: ;epid=5553A23860;tag=695d86eb9c TO: ;tag=8091rHjK8Q9rj CSEQ: 2 BYE CALL-ID: 326ef4fc-3044-122b-4f8f-0002b335f374 MAX-FORWARDS: 70 VIA: SIP/2.0/TCP 10.1.16.10:5065;branch=z9hG4bK98f9abef CONTENT-LENGTH: 0 USER-AGENT: RTCC/3.0.0.0 ------------------------------------------------------------------------ 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:402 switch_core_session_run() sofia/default/448@10.1.16.10;transport=tcp Running State Change CS_INIT 2007-12-28 16:02:55 [DEBUG] mod_sofia.c:313 sofia_on_hangup() Sending BYE to sofia/default/501@10.1.16.10;transport=tcp send 475 bytes to tcp/[10.1.16.10]:5065 at 00:02:55.852038: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 10.1.16.10:5065;branch=z9hG4bK98f9abef;rport=5065 FROM: ;epid=5553A23860;tag=695d86eb9c TO: ;tag=8091rHjK8Q9rj CALL-ID: 326ef4fc-3044-122b-4f8f-0002b335f374 CSEQ: 2 BYE User-Agent: FreeSWITCH-1.0.pre3 (7007M)-mod_sofia Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: 100rel, precondition, timer Content-Length: 0 ------------------------------------------------------------------------ 2007-12-28 16:02:55 [DEBUG] sofia.c:1363 sofia_handle_sip_i_state() Channel sofia/default/501@10.1.16.10;transport=tcp entering state [terminated] gfnua: nua_r_bye with invalid handle (nil) 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:45 switch_core_standard_on_hangup() Standard HANGUP sofia/default/501@10.1.16.10;transport=tcp, cause: NORMAL_CLEARING 2007-12-28 16:02:55 [DEBUG] switch_core_session.c:691 switch_core_session_thread() Session 8 (sofia/default/501@10.1.16.10;transport=tcp) Locked, Waiting on external entities 2007-12-28 16:02:55 [NOTICE] switch_core_session.c:697 switch_core_session_thread() Session 8 (sofia/default/501@10.1.16.10;transport=tcp) Ended 2007-12-28 16:02:55 [NOTICE] switch_core_session.c:699 switch_core_session_thread() Close Channel sofia/default/501@10.1.16.10;transport=tcp [CS_HANGUP] 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:414 switch_core_session_run() (sofia/default/448@10.1.16.10;transport=tcp) State INIT 2007-12-28 16:02:55 [DEBUG] mod_sofia.c:87 sofia_on_init() sofia/default/448@10.1.16.10;transport=tcp SOFIA INIT send 1064 bytes to tcp/[10.1.16.10]:5060 at 00:02:55.863357: ------------------------------------------------------------------------ INVITE sip:448@10.1.16.10;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 10.1.16.1;branch=z9hG4bKFgyF45v9BaKNQ Max-Forwards: 69 From: "Ady" ;tag=992ttc3p50ZBe To: ;transport=tcp Call-ID: 3facf50b-3044-122b-4f8f-0002b335f374 CSeq: 93324951 INVITE Contact: User-Agent: FreeSWITCH-1.0.pre3 (7007M)-mod_sofia Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: 100rel, precondition, timer Referred-By: Min-SE: 120 Content-Type: application/sdp Content-Disposition: session Content-Length: 318 Remote-Party-ID: "Ady" ;screen=yes;privacy=off v=0 o=FreeSWITCH 4407518463699422763 6402185796614146902 IN IP4 66.92.40.44 s=FreeSWITCH c=IN IP4 10.1.16.1 t=0 0 a=sendrecv m=audio 27726 RTP/AVP 0 9 8 101 13 a=rtpmap:0 PCMU/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:20 ------------------------------------------------------------------------ recv 257 bytes from tcp/[10.1.16.10]:5060 at 00:02:55.865244: ------------------------------------------------------------------------ SIP/2.0 100 Trying FROM: "Ady";tag=992ttc3p50ZBe TO: ;transport=tcp CSEQ: 93324951 INVITE CALL-ID: 3facf50b-3044-122b-4f8f-0002b335f374 VIA: SIP/2.0/TCP 10.1.16.1;branch=z9hG4bKFgyF45v9BaKNQ CONTENT-LENGTH: 0 ------------------------------------------------------------------------ 2007-12-28 16:02:55 [DEBUG] sofia.c:178 sofia_event_callback() event [nua_i_state] status [0][INVITE sent] session: sofia/default/448@10.1.16.10;transport=tcp 2007-12-28 16:02:55 [DEBUG] sofia.c:1363 sofia_handle_sip_i_state() Channel sofia/default/448@10.1.16.10;transport=tcp entering state [calling] 2007-12-28 16:02:55 [DEBUG] mod_sofia.c:100 sofia_on_init() sofia/default/448@10.1.16.10;transport=tcp State Change CS_INIT -> CS_RING 2007-12-28 16:02:55 [DEBUG] switch_core_session.c:633 switch_core_session_signal_state_change() Kill sofia/default/448@10.1.16.10;transport=tcp [BREAK] 2007-12-28 16:02:55 [DEBUG] switch_ivr_originate.c:729 switch_ivr_originate() Raw Codec Activation Success L16@8000hz 1 channel 20ms 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:402 switch_core_session_run() sofia/default/448@10.1.16.10;transport=tcp Running State Change CS_RING 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:417 switch_core_session_run() (sofia/default/448@10.1.16.10;transport=tcp) State RING 2007-12-28 16:02:55 [DEBUG] mod_sofia.c:117 sofia_on_ring() sofia/default/448@10.1.16.10;transport=tcp SOFIA RING 2007-12-28 16:02:55 [DEBUG] switch_ivr_originate.c:48 originate_on_ring() sofia/default/448@10.1.16.10;transport=tcp State Change CS_RING -> CS_HOLD 2007-12-28 16:02:55 [DEBUG] switch_core_session.c:633 switch_core_session_signal_state_change() Kill sofia/default/448@10.1.16.10;transport=tcp [BREAK] 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:402 switch_core_session_run() sofia/default/448@10.1.16.10;transport=tcp Running State Change CS_HOLD 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:435 switch_core_session_run() (sofia/default/448@10.1.16.10;transport=tcp) State HOLD 2007-12-28 16:02:55 [DEBUG] switch_core_state_machine.c:220 switch_core_standard_on_hold() Standard HOLD hrecv 355 bytes from tcp/[10.1.16.10]:5060 at 00:02:55.905791: ------------------------------------------------------------------------ SIP/2.0 302 Moved Temporarily FROM: "Ady";tag=992ttc3p50ZBe TO: ;transport=tcp;tag=6d44522c74 CSEQ: 93324951 INVITE CALL-ID: 3facf50b-3044-122b-4f8f-0002b335f374 VIA: SIP/2.0/TCP 10.1.16.1;branch=z9hG4bKFgyF45v9BaKNQ CONTACT: CONTENT-LENGTH: 0 SERVER: RTCC/3.0.0.0 ------------------------------------------------------------------------ send 314 bytes to tcp/[10.1.16.10]:5060 at 00:02:55.906710: ------------------------------------------------------------------------ ACK sip:448@10.1.16.10;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 10.1.16.1;branch=z9hG4bKFgyF45v9BaKNQ Max-Forwards: 69 From: "Ady" ;tag=992ttc3p50ZBe To: ;transport=tcp;tag=6d44522c74 Call-ID: 3facf50b-3044-122b-4f8f-0002b335f374 CSeq: 93324951 ACK Content-Length: 0 ------------------------------------------------------------------------ send 1069 bytes to tcp/[10.1.16.10]:5065 at 00:02:55.907682: ------------------------------------------------------------------------ INVITE sip:448@10.1.16.10:5065;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 10.1.16.1;branch=z9hG4bKgSQ850DD9j97j Max-Forwards: 69 From: "Ady" ;tag=992ttc3p50ZBe To: ;transport=tcp Call-ID: 3facf50b-3044-122b-4f8f-0002b335f374 CSeq: 93324952 INVITE Contact: User-Agent: FreeSWITCH-1.0.pre3 (7007M)-mod_sofia Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: 100rel, precondition, timer Referred-By: Min-SE: 120 Content-Type: application/sdp Content-Disposition: session Content-Length: 318 Remote-Party-ID: "Ady" ;screen=yes;privacy=off v=0 o=FreeSWITCH 4407518463699422763 6402185796614146902 IN IP4 66.92.40.44 s=FreeSWITCH c=IN IP4 10.1.16.1 t=0 0 a=sendrecv m=audio 27726 RTP/AVP 0 9 8 101 13 a=rtpmap:0 PCMU/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:20 ------------------------------------------------------------------------ recv 257 bytes from tcp/[10.1.16.10]:5065 at 00:02:55.909863: ------------------------------------------------------------------------ SIP/2.0 100 Trying FROM: "Ady";tag=992ttc3p50ZBe TO: ;transport=tcp CSEQ: 93324952 INVITE CALL-ID: 3facf50b-3044-122b-4f8f-0002b335f374 VIA: SIP/2.0/TCP 10.1.16.1;branch=z9hG4bKgSQ850DD9j97j CONTENT-LENGTH: 0 ------------------------------------------------------------------------ 2007-12-28 16:02:55 [DEBUG] sofia.c:1363 sofia_handle_sip_i_state() Channel sofia/default/448@10.1.16.10;transport=tcp entering state [calling] recv 311 bytes from tcp/[10.1.16.10]:5065 at 00:02:55.916217: ------------------------------------------------------------------------ SIP/2.0 180 Ringing FROM: "Ady";tag=992ttc3p50ZBe TO: ;transport=tcp;epid=5553A23860;tag=b14ab11ac1 CSEQ: 93324952 INVITE CALL-ID: 3facf50b-3044-122b-4f8f-0002b335f374 VIA: SIP/2.0/TCP 10.1.16.1;branch=z9hG4bKgSQ850DD9j97j CONTENT-LENGTH: 0 SERVER: RTCC/3.0.0.0 ------------------------------------------------------------------------ recv 694 bytes from tcp/[10.1.16.10]:5065 at 00:02:56.057263: ------------------------------------------------------------------------ SIP/2.0 200 OK FROM: "Ady";tag=992ttc3p50ZBe TO: ;transport=tcp;epid=5553A23860;tag=b14ab11ac1 CSEQ: 93324952 INVITE CALL-ID: 3facf50b-3044-122b-4f8f-0002b335f374 VIA: SIP/2.0/TCP 10.1.16.1;branch=z9hG4bKgSQ850DD9j97j CONTACT: ;automata CONTENT-LENGTH: 191 CONTENT-TYPE: application/sdp ALLOW: UPDATE SERVER: RTCC/3.0.0.0 ALLOW: Ack, Cancel, Bye,Invite,Message,Info,Service,Options,BeNotify v=0 o=- 0 0 IN IP4 10.1.16.10 s=Microsoft Exchange Speech Engine c=IN IP4 10.1.16.10 t=0 0 m=audio 60800 RTP/AVP 0 8 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ send 394 bytes to tcp/[10.1.16.10]:5065 at 00:02:56.059192: ------------------------------------------------------------------------ ACK sip:dune.domain.local:5065;transport=Tcp;maddr=10.1.16.10 SIP/2.0 Via: SIP/2.0/TCP 10.1.16.1;branch=z9hG4bKH2g17Uyg6UZte Max-Forwards: 70 From: "Ady" ;tag=992ttc3p50ZBe To: ;transport=tcp;tag=b14ab11ac1 Call-ID: 3facf50b-3044-122b-4f8f-0002b335f374 CSeq: 93324952 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ f2007-12-28 16:02:56 [DEBUG] sofia.c:178 sofia_event_callback() event [nua_r_invite] status [180][Ringing] session: sofia/default/448@10.1.16.10;transport=tcp g2007-12-28 16:02:56 [DEBUG] sofia.c:178 sofia_event_callback() event [nua_i_state] status [180][Ringing] session: sofia/default/448@10.1.16.10;transport=tcp 2007-12-28 16:02:56 [DEBUG] sofia.c:1363 sofia_handle_sip_i_state() Channel sofia/default/448@10.1.16.10;transport=tcp entering state [proceeding] 2007-12-28 16:02:56 [NOTICE] sofia.c:1395 sofia_handle_sip_i_state() Ring-Ready sofia/default/448@10.1.16.10;transport=tcp! 2007-12-28 16:02:56 [DEBUG] sofia.c:1363 sofia_handle_sip_i_state() Channel sofia/default/448@10.1.16.10;transport=tcp entering state [ready] 2007-12-28 16:02:56 [DEBUG] sofia.c:1367 sofia_handle_sip_i_state() Remote SDP: v=0 o=- 0 0 IN IP4 10.1.16.10 s=Microsoft Exchange Speech Engine c=IN IP4 10.1.16.10 t=0 0 m=audio 60800 RTP/AVP 0 8 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 2007-12-28 16:02:56 [DEBUG] sofia_glue.c:1483 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[PCMU:0:8000] 2007-12-28 16:02:56 [DEBUG] sofia_glue.c:1062 sofia_glue_tech_set_codec() Set Codec sofia/default/448@10.1.16.10;transport=tcp PCMU/8000 20 ms 160 samples 2007-12-28 16:02:56 [DEBUG] sofia_glue.c:1447 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101 2007-12-28 16:02:56 [DEBUG] sofia_glue.c:1137 sofia_glue_activate_rtp() AUDIO RTP [sofia/default/448@10.1.16.10;transport=tcp] 10.1.16.1:27726->10.1.16.10:60800 codec: 0 ms: 20 2007-12-28 16:02:56 [DEBUG] switch_rtp.c:589 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms 2007-12-28 16:02:56 [DEBUG] switch_channel.c:1387 switch_channel_perform_mark_answered() Kill sofia/default/498@10.1.16.1:5061 [BREAK] 2007-12-28 16:02:56 [NOTICE] sofia.c:1650 sofia_handle_sip_i_state() Channel [sofia/default/448@10.1.16.10;transport=tcp] has been answered 2007-12-28 16:02:56 [DEBUG] switch_ivr_originate.c:945 switch_ivr_originate() Originate Resulted in Success: [sofia/default/448@10.1.16.10;transport=tcp] 2007-12-28 16:02:56 [DEBUG] switch_core_session.c:350 switch_core_session_receive_message() Kill sofia/default/448@10.1.16.10;transport=tcp [BREAK] 2007-12-28 16:02:56 [DEBUG] switch_core_session.c:350 switch_core_session_receive_message() Kill sofia/default/498@10.1.16.1:5061 [BREAK] 2007-12-28 16:02:56 [DEBUG] switch_ivr_bridge.c:657 switch_ivr_multi_threaded_bridge() sofia/default/448@10.1.16.10;transport=tcp State Change CS_HOLD -> CS_LOOPBACK 2007-12-28 16:02:56 [DEBUG] switch_core_session.c:633 switch_core_session_signal_state_change() Kill sofia/default/448@10.1.16.10;transport=tcp [BREAK] 2007-12-28 16:02:56 [DEBUG] switch_core_session.c:350 switch_core_session_receive_message() Kill sofia/default/498@10.1.16.1:5061 [BREAK] 2007-12-28 16:02:56 [DEBUG] switch_core_state_machine.c:402 switch_core_session_run() sofia/default/448@10.1.16.10;transport=tcp Running State Change CS_LOOPBACK 2007-12-28 16:02:56 [DEBUG] switch_core_state_machine.c:426 switch_core_session_run() (sofia/default/448@10.1.16.10;transport=tcp) State LOOPBACK 2007-12-28 16:02:56 [DEBUG] mod_sofia.c:340 sofia_on_loopback() SOFIA LOOPBACK 2007-12-28 16:02:56 [DEBUG] sofia.c:178 sofia_event_callback() event [nua_i_error] status [500][Responding to a Non-Existing Request] session: sofia/default/498@10.1.16.1:5061 2007-12-28 16:03:00 [CONSOLE] switch_console.c:134 switch_console_process() Unknown Command: fghgfhfg freeswitch@rim> freeswitch@rim> freeswitch@rim> freeswitch@rim> freeswitch@rim> freeswitch@rim> freeswitch@rim> show channels API CALL [show(channels)] output: uuid,created,name,state,cid_name,cid_num,ip_addr,dest,application,application_data,read_codec,read_rate,write_codec,write_rate 822fc285-bac5-4532-bca2-21f6bb475dfc,2007-12-28 16:02:33,sofia/default/498@10.1.16.1:5061,CS_EXECUTE,Ady,498,10.1.16.1,448,bridge,sofia/default/448@10.1.16.10;transport=tcp,PCMU,8000,PCMU,8000 41bbac69-b733-465b-a107-95a8459d0e1b,2007-12-28 16:02:55,sofia/default/448@10.1.16.10;transport=tcp,CS_LOOPBACK,Ady,498,10.1.16.1,default/448@10.1.16.10;transport=tcp,,,PCMU,8000,PCMU,8000 2 total.