All pastes #835681 Raw Edit

Untitled

public text v1 · immutable
#835681 ·published 2007-12-29 00:02 UTC
rendered paste body
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: <sip:501@10.1.16.10>;epid=5553A23860;tag=695d86eb9c
   TO: <sip:498@10.1.16.1>;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: <sip:dune.domain.local:5065;transport=Tcp;maddr=10.1.16.10;ms-opaque=f448e28078403412>;automata
   CONTENT-LENGTH: 0
   REFER-TO: <sip:448@10.1.16.1:5060;transport=tcp;user=phone>
   REFERRED-BY: <sip:501@10.1.16.10>
   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: <sip:501@10.1.16.10>;epid=5553A23860;tag=695d86eb9c
   TO: <sip:498@10.1.16.1>;tag=8091rHjK8Q9rj
   CALL-ID: 326ef4fc-3044-122b-4f8f-0002b335f374
   CSEQ: 1 REFER
   Contact: <sip:mod_sofia@10.1.16.1:5060;transport=tcp>
   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" <sip:498@10.1.16.1>;tag=8091rHjK8Q9rj
   To: <sip:501@10.1.16.10>;transport=tcp;tag=695d86eb9c
   Call-ID: 326ef4fc-3044-122b-4f8f-0002b335f374
   CSeq: 93324942 NOTIFY
   Contact: <sip:mod_sofia@10.1.16.1:5060;transport=tcp>
   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"<sip:498@10.1.16.1>;tag=8091rHjK8Q9rj
   TO: <sip:501@10.1.16.10>;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: <sip:501@10.1.16.10>;epid=5553A23860;tag=695d86eb9c
   TO: <sip:498@10.1.16.1>;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: <sip:501@10.1.16.10>;epid=5553A23860;tag=695d86eb9c
   TO: <sip:498@10.1.16.1>;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" <sip:498@10.1.16.1>;tag=992ttc3p50ZBe
   To: <sip:448@10.1.16.10>;transport=tcp
   Call-ID: 3facf50b-3044-122b-4f8f-0002b335f374
   CSeq: 93324951 INVITE
   Contact: <sip:mod_sofia@10.1.16.1:5060;transport=tcp>
   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: <sip:501@10.1.16.10>
   Min-SE: 120
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 318
   Remote-Party-ID: "Ady" <sip:498@10.1.16.1>;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"<sip:498@10.1.16.1>;tag=992ttc3p50ZBe
   TO: <sip:448@10.1.16.10>;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"<sip:498@10.1.16.1>;tag=992ttc3p50ZBe
   TO: <sip:448@10.1.16.10>;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: <sip:448@10.1.16.10:5065;transport=tcp>
   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" <sip:498@10.1.16.1>;tag=992ttc3p50ZBe
   To: <sip:448@10.1.16.10>;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" <sip:498@10.1.16.1>;tag=992ttc3p50ZBe
   To: <sip:448@10.1.16.10>;transport=tcp
   Call-ID: 3facf50b-3044-122b-4f8f-0002b335f374
   CSeq: 93324952 INVITE
   Contact: <sip:mod_sofia@10.1.16.1:5060;transport=tcp>
   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: <sip:501@10.1.16.10>
   Min-SE: 120
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 318
   Remote-Party-ID: "Ady" <sip:498@10.1.16.1>;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"<sip:498@10.1.16.1>;tag=992ttc3p50ZBe
   TO: <sip:448@10.1.16.10>;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"<sip:498@10.1.16.1>;tag=992ttc3p50ZBe
   TO: <sip:448@10.1.16.10>;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"<sip:498@10.1.16.1>;tag=992ttc3p50ZBe
   TO: <sip:448@10.1.16.10>;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: <sip:dune.domain.local:5065;transport=Tcp;maddr=10.1.16.10>;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" <sip:498@10.1.16.1>;tag=992ttc3p50ZBe
   To: <sip:448@10.1.16.10>;transport=tcp;tag=b14ab11ac1
   Call-ID: 3facf50b-3044-122b-4f8f-0002b335f374
   CSeq: 93324952 ACK
   Contact: <sip:mod_sofia@10.1.16.1:5060;transport=tcp>
   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.