2008-04-11 13:46:46 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/38514001702 entering state [ready] 2008-04-11 13:46:46 [DEBUG] sofia.c:1599 sofia_handle_sip_i_state() Remote SDP: v=0 o=MxSIP 0 81 IN IP4 89.18.37.100 s=SIP Call c=IN IP4 89.18.37.100 t=0 0 m=audio 5024 RTP/AVP 8 a=rtpmap:8 PCMA/8000 2008-04-11 13:46:46 [DEBUG] sofia_glue.c:2011 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMA:8:8000]/[PCMA:8:8000] 2008-04-11 13:46:46 [DEBUG] sofia_glue.c:1333 sofia_glue_tech_set_codec() Set Codec sofia/default/38514001702 PCMA/8000 20 ms 160 samples 2008-04-11 13:46:46 [DEBUG] sofia_glue.c:1523 sofia_glue_activate_rtp() AUDIO RTP [sofia/default/38514001702] 89.18.32.19:25440->89.18.37.100:5024 codec: 8 ms: 20 2008-04-11 13:46:46 [DEBUG] switch_rtp.c:716 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms 2008-04-11 13:46:46 [DEBUG] switch_channel.c:1506 switch_channel_perform_mark_answered() Kill sofia/outbound/38516184904@10.0.3.220 [BREAK] 2008-04-11 13:46:46 [NOTICE] sofia.c:1945 sofia_handle_sip_i_state() Channel [sofia/default/38514001702] has been answered 2008-04-11 13:46:46 [DEBUG] sofia_glue.c:1523 sofia_glue_activate_rtp() AUDIO RTP [sofia/outbound/38516184904@10.0.3.220] 89.18.32.19:29046->10.0.3.220:17396 codec: 8 ms: 20 2008-04-11 13:46:46 [DEBUG] switch_rtp.c:716 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms 2008-04-11 13:46:46 [DEBUG] mod_sofia.c:376 sofia_answer_channel() Local SDP sofia/outbound/38516184904@10.0.3.220: v=0 o=FreeSWITCH 1207885360 1207885361 IN IP4 89.18.32.19 s=FreeSWITCH c=IN IP4 89.18.32.19 t=0 0 a=sendrecv m=audio 29046 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 2008-04-11 13:46:46 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/outbound/38516184904@10.0.3.220 [BREAK] 2008-04-11 13:46:46 [NOTICE] switch_ivr_originate.c:1171 switch_ivr_originate() Channel [sofia/outbound/38516184904@10.0.3.220] has been answered 2008-04-11 13:46:46 [DEBUG] switch_ivr_originate.c:1205 switch_ivr_originate() Originate Resulted in Success: [sofia/default/38514001702] 2008-04-11 13:46:46 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/default/38514001702 [BREAK] 2008-04-11 13:46:46 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/outbound/38516184904@10.0.3.220 [BREAK] 2008-04-11 13:46:46 [DEBUG] switch_ivr_bridge.c:756 switch_ivr_multi_threaded_bridge() sofia/default/38514001702 State Change CS_HOLD -> CS_LOOPBACK 2008-04-11 13:46:46 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/38514001702 [BREAK] send 897 bytes to udp/[10.0.3.220]:5090 at 11:46:46.446911: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.3.220:5090;rport=5090;branch=z9hG4bK293463607 From: "10.0.3.10" ;tag=1005463975 To: ;tag=2Sgt80aptejjg Call-ID: 1414260367@10.0.3.220 CSeq: 19 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.0.pre4-8058 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO Supported: 100rel, precondition, timer Allow-Events: talk Min-SE: 120 Content-Type: application/sdp Content-Disposition: session Content-Length: 272 v=0 o=FreeSWITCH 6013977101500251822 7042482777030961138 IN IP4 89.18.32.19 s=FreeSWITCH c=IN IP4 89.18.32.19 t=0 0 a=sendrecv m=audio 29046 RTP/AVP 8 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 ------------------------------------------------------------------------ 2008-04-11 13:46:46 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/outbound/38516184904@10.0.3.220 entering state [completed] recv 404 bytes from udp/[10.0.3.220]:5090 at 11:46:46.459555: ------------------------------------------------------------------------ ACK sip:mod_sofia@89.18.32.19:5080;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.0.3.220:5090;rport;branch=z9hG4bK1807442927 From: "10.0.3.10" ;tag=1005463975 To: ;tag=2Sgt80aptejjg Call-ID: 1414260367@10.0.3.220 CSeq: 19 ACK Max-Forwards: 20 Contact: User-Agent: sip-to-h323/0.9.0 Content-Length: 0 ------------------------------------------------------------------------ 2008-04-11 13:46:46 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/outbound/38516184904@10.0.3.220 entering state [ready] 2008-04-11 13:46:46 [DEBUG] switch_core_state_machine.c:440 switch_core_session_run() (sofia/default/38514001702) State HOLD going to sleep 2008-04-11 13:46:46 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/38514001702 Running State Change CS_LOOPBACK 2008-04-11 13:46:46 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/38514001702) State LOOPBACK 2008-04-11 13:46:46 [DEBUG] mod_sofia.c:314 sofia_on_loopback() SOFIA LOOPBACK freeswitch@softsw00> freeswitch@softsw00> recv 440 bytes from udp/[89.18.37.100]:5062 at 11:47:25.493537: ------------------------------------------------------------------------ BYE sip:mod_sofia@89.18.32.19:5060 SIP/2.0 Via: SIP/2.0/UDP 89.18.37.100:5062;branch=z9hG4bKc22903e25 Max-Forwards: 70 Content-Length: 0 To: "10.0.3.10" ;tag=KtFgg4Z384S5j From: ;tag=01ec8a090df17a1 Call-ID: cc981044-825f-122b-1ca9-001e0b83659c CSeq: 802101929 BYE Supported: timer Supported: replaces User-Agent: Patton SN4112 JS EUI MxSF v3.2.8.45 00A0BA02B814 ------------------------------------------------------------------------ send 498 bytes to udp/[89.18.37.100]:5062 at 11:47:25.494066: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 89.18.37.100:5062;branch=z9hG4bKc22903e25 From: ;tag=01ec8a090df17a1 To: "10.0.3.10" ;tag=KtFgg4Z384S5j Call-ID: cc981044-825f-122b-1ca9-001e0b83659c CSeq: 802101929 BYE User-Agent: FreeSWITCH-mod_sofia/1.0.pre4-8058 Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO, PUBLISH Supported: 100rel, precondition, timer Content-Length: 0 ------------------------------------------------------------------------ 2008-04-11 13:47:25 [DEBUG] sofia.c:1595 sofia_handle_sip_i_state() Channel sofia/default/38514001702 entering state [terminated] 2008-04-11 13:47:25 [NOTICE] sofia.c:1992 sofia_handle_sip_i_state() Hangup sofia/default/38514001702 [CS_LOOPBACK] [NORMAL_CLEARING] 2008-04-11 13:47:25 [DEBUG] switch_channel.c:1355 switch_channel_perform_hangup() Kill sofia/default/38514001702 [KILL] 2008-04-11 13:47:25 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/default/38514001702 [BREAK] 2008-04-11 13:47:25 [DEBUG] switch_ivr_bridge.c:275 audio_bridge_thread() read: sofia/default/38514001702 Bad Frame.... Bubye! 2008-04-11 13:47:25 [DEBUG] switch_ivr_bridge.c:344 audio_bridge_thread() Kill sofia/outbound/38516184904@10.0.3.220 [BREAK] 2008-04-11 13:47:25 [DEBUG] switch_ivr_bridge.c:347 audio_bridge_thread() BRIDGE THREAD DONE [sofia/default/38514001702] 2008-04-11 13:47:25 [DEBUG] switch_core_state_machine.c:431 switch_core_session_run() (sofia/default/38514001702) State LOOPBACK going to sleep 2008-04-11 13:47:25 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/default/38514001702 Running State Change CS_HANGUP 2008-04-11 13:47:25 [DEBUG] switch_core_state_machine.c:392 switch_core_session_run() (sofia/default/38514001702) State HANGUP 2008-04-11 13:47:25 [DEBUG] mod_sofia.c:255 sofia_on_hangup() Channel sofia/default/38514001702 hanging up, cause: NORMAL_CLEARING 2008-04-11 13:47:25 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP sofia/default/38514001702, cause: NORMAL_CLEARING 2008-04-11 13:47:25 [DEBUG] switch_core_state_machine.c:392 switch_core_session_run() (sofia/default/38514001702) State HANGUP going to sleep 2008-04-11 13:47:25 [DEBUG] switch_core_session.c:730 switch_core_session_thread() Session 145 (sofia/default/38514001702) Locked, Waiting on external entities 2008-04-11 13:47:25 [DEBUG] switch_core_session.c:383 switch_core_session_receive_message() Kill sofia/outbound/38516184904@10.0.3.220 [BREAK] 2008-04-11 13:47:25 [DEBUG] switch_ivr_bridge.c:344 audio_bridge_thread() Kill sofia/default/38514001702 [BREAK] 2008-04-11 13:47:25 [DEBUG] switch_ivr_bridge.c:347 audio_bridge_thread() BRIDGE THREAD DONE [sofia/outbound/38516184904@10.0.3.220] 2008-04-11 13:47:25 [NOTICE] switch_core_state_machine.c:156 switch_core_standard_on_execute() Hangup sofia/outbound/38516184904@10.0.3.220 [CS_EXECUTE] [NORMAL_CLEARING] 2008-04-11 13:47:25 [DEBUG] switch_channel.c:1355 switch_channel_perform_hangup() Kill sofia/outbound/38516184904@10.0.3.220 [KILL] 2008-04-11 13:47:25 [DEBUG] switch_core_session.c:670 switch_core_session_signal_state_change() Kill sofia/outbound/38516184904@10.0.3.220 [BREAK] 2008-04-11 13:47:25 [DEBUG] switch_core_state_machine.c:428 switch_core_session_run() (sofia/outbound/38516184904@10.0.3.220) State EXECUTE going to sleep 2008-04-11 13:47:25 [DEBUG] switch_core_state_machine.c:364 switch_core_session_run() sofia/outbound/38516184904@10.0.3.220 Running State Change CS_HANGUP 2008-04-11 13:47:25 [DEBUG] switch_core_state_machine.c:392 switch_core_session_run() (sofia/outbound/38516184904@10.0.3.220) State HANGUP send 626 bytes to udp/[10.0.3.220]:5090 at 11:47:25.500778: 2008-04-11 13:47:25 [DEBUG] mod_sofia.c:255 sofia_on_hangup() Channel sofia/outbound/38516184904@10.0.3.220 hanging up, cause: NORMAL_CLEARING BYE sip:38516184904@10.0.3.220:5090 SIP/2.0 Via: SIP/2.0/UDP 89.18.32.19:5080;rport;branch=z9hG4bKK5Zr11t0jaS2m Max-Forwards: 70 From: ;tag=2Sgt80aptejjg To: "10.0.3.10" ;tag=1005463975 Call-ID: 1414260367@10.0.3.220 CSeq: 97838886 BYE Contact: 2008-04-11 13:47:25 [DEBUG] mod_sofia.c:287 sofia_on_hangup() Sending BYE to sofia/outbound/38516184904@10.0.3.220 2008-04-11 13:47:25 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP sofia/outbound/38516184904@10.0.3.220, cause: NORMAL_CLEARING User-Agent: FreeSWITCH-mod_sofia/1.0.pre4-8058 2008-04-11 13:47:25 [DEBUG] switch_core_state_machine.c:392 switch_core_session_run() (sofia/outbound/38516184904@10.0.3.220) State HANGUP going to sleep Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO 2008-04-11 13:47:25 [DEBUG] switch_core_session.c:730 switch_core_session_thread() Session 144 (sofia/outbound/38516184904@10.0.3.220) Locked, Waiting on external entities Supported: 100rel, precondition, timer Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------ 2008-04-11 13:47:25 [NOTICE] switch_core_session.c:748 switch_core_session_thread() Session 144 (sofia/outbound/38516184904@10.0.3.220) Ended 2008-04-11 13:47:25 [NOTICE] switch_core_session.c:750 switch_core_session_thread() Close Channel sofia/outbound/38516184904@10.0.3.220 [CS_HANGUP] 2008-04-11 13:47:25 [NOTICE] switch_core_session.c:748 switch_core_session_thread() Session 145 (sofia/default/38514001702) Ended 2008-04-11 13:47:25 [NOTICE] switch_core_session.c:750 switch_core_session_thread() Close Channel sofia/default/38514001702 [CS_HANGUP] recv 336 bytes from udp/[10.0.3.220]:5090 at 11:47:25.511122: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 89.18.32.19:5080;rport=5080;branch=z9hG4bKK5Zr11t0jaS2m;received=89.18.32.19 From: ;tag=2Sgt80aptejjg To: "10.0.3.10" ;tag=1005463975 Call-ID: 1414260367@10.0.3.220 CSeq: 97838886 BYE Server: sip-to-h323/0.9.0 Content-Length: 0 ------------------------------------------------------------------------ recv 390 bytes from udp/[10.0.3.220]:5090 at 11:47:25.530548: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 89.18.32.19:5080;rport=5080;branch=z9hG4bKK5Zr11t0jaS2m;received=89.18.32.19 Call-ID: 1414260367@10.0.3.220 CSeq: 97838886 BYE Server: sip-to-h323/0.9.0 Allow: ACK, INVITE, BYE, CANCEL, REGISTER, OPTIONS, INFO Content-Length: 0 ------------------------------------------------------------------------