rendered paste bodyfreeswitch@svidev06b> tport_wakeup_pri(0x8091130): events IN
tport_recv_event(0x8091130)
tport_recv_iovec(0x8091130) msg 0x80c31a8 from (udp/10.133.92.53:5060) has 908 bytes, veclen = 1
recv 908 bytes from udp/[10.60.2.20]:21778 at 15:04:13.241975:
------------------------------------------------------------------------
INVITE sip:5399@svidev06b.tst33.cvf SIP/2.0
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-0c39062a9d626d65-1--d87543-
Max-Forwards: 70
Contact: <sip:key2@10.60.2.20:21778>
To: "5399"<sip:5399@svidev06b.tst33.cvf>
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=c1788339
Call-ID: ZmZjNTAxOWEwMWY2YThmMDhhYmYxMDllMzllZmRhNGE.
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
Content-Type: application/sdp
User-Agent: X-Lite release 1011s stamp 41150
Content-Length: 369
v=0
o=- 8 2 IN IP4 10.60.2.20
s=CounterPath X-Lite 3.0
c=IN IP4 10.60.2.20
t=0 0
m=audio 45136 RTP/AVP 100 106 0 105 8 101
a=fmtp:101 0-15
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:105 SPEEX-FEC/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
m=video 26324 RTP/AVP 34
a=fmtp:34 QCIF=1 MaxBR=1960
a=rtpmap:34 H263/90000
a=sendrecv
------------------------------------------------------------------------
tport_deliver(0x8091130): msg 0x80c31a8 (908 bytes) from udp/10.60.2.20:5060/sip next=(nil)
nta: received INVITE sip:5399@svidev06b.tst33.cvf SIP/2.0 (CSeq 1)
nta: INVITE (1) going to a default leg
nta: timer set to 200 ms
nua: nua_stack_process_request: entering
nua: nh_create: entering
nua: nh_create_handle: entering
nua: nua_stack_set_params: entering
soa_clone(static::0x808e7b8, 0x808e4e0, 0x80c7cc0) called
soa_set_params(static::0x80ca310, ...) called
soa_set_params(static::0x80ca310, ...) called
nta_leg_create(0x80c7c18)
soa_init_offer_answer(static::0x80ca310) called
soa_set_remote_sdp(static::0x80ca310, (nil), 0x80959eb, 369) called
nua(0x80c7cc0): adding session usage
tport_tsend(0x8091130) tpn = UDP/10.60.2.20:21778
tport_resolve addrinfo = 10.60.2.20:21778
tport_by_addrinfo(0x8091130): not found by name UDP/10.60.2.20:21778
tport_vsend(0x8091130): 331 bytes of 331 to UDP/10.60.2.20:21778
tport_vsend returned 331
send 331 bytes to udp/[10.60.2.20]:21778 at 15:04:13.243270:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-0c39062a9d626d65-1--d87543-
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=c1788339
To: "5399"<sip:5399@svidev06b.tst33.cvf>
Call-ID: ZmZjNTAxOWEwMWY2YThmMDhhYmYxMDllMzllZmRhNGE.
CSeq: 1 INVITE
User-Agent: FreeSWITCH(mod_sofia)
Content-Length: 0
------------------------------------------------------------------------
nta: sent 100 Trying for INVITE (1)
nua(0x80c7cc0): event i_invite 100 Trying
nua(0x80c7cc0): call state changed: init -> received, received offer
soa_get_remote_sdp(static::0x80ca310, [0x437c8de8], [0x437c8de4], [(nil)]) called
nua(0x80c7cc0): event i_state 100 Trying
nua: nua_event: entering
nua: nua_handle_bind: entering
nua: nua_event: entering
2007-07-24 17:04:13 [NOTICE] switch_channel.c:381 switch_channel_set_name() New Chan sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [23abc980-39f7-11dc-b76a-7f299aba097e]
2007-07-24 17:04:13 [DEBUG] sofia.c:1028 sofia_handle_sip_i_state() Channel sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 entering state [received]
2007-07-24 17:04:13 [DEBUG] sofia.c:1032 sofia_handle_sip_i_state() Remote SDP:
v=0
o=- 8 2 IN IP4 10.60.2.20
s=CounterPath X-Lite 3.0
c=IN IP4 10.60.2.20
t=0 0
m=audio 45136 RTP/AVP 100 106 0 105 8 101
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:105 SPEEX-FEC/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
m=video 26324 RTP/AVP 34
a=rtpmap:34 H263/90000
a=fmtp:34 QCIF=1 MaxBR=1960
2007-07-24 17:04:13 [DEBUG] sofia_glue.c:1202 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX:100:16000]/[PCMU:0:8000]
2007-07-24 17:04:13 [DEBUG] sofia_glue.c:1202 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX-FEC:106:16000]/[PCMU:0:8000]
2007-07-24 17:04:13 [DEBUG] sofia_glue.c:1202 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[PCMU:0:8000]
2007-07-24 17:04:13 [DEBUG] sofia_glue.c:812 sofia_glue_tech_set_codec() Set Codec sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 PCMU/8000 20 ms 160 samples
2007-07-24 17:04:13 [DEBUG] sofia_glue.c:1166 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101
2007-07-24 17:04:13 [DEBUG] sofia.c:1132 sofia_handle_sip_i_state() sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 State Change CS_NEW -> CS_INIT
2007-07-24 17:04:13 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:04:13 [DEBUG] switch_core_state_machine.c:367 switch_core_session_run() (sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060) State INIT
2007-07-24 17:04:13 [DEBUG] mod_sofia.c:92 sofia_on_init() SOFIA INIT
2007-07-24 17:04:13 [DEBUG] mod_sofia.c:105 sofia_on_init() sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 State Change CS_INIT -> CS_RING
2007-07-24 17:04:13 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:04:13 [DEBUG] switch_core_state_machine.c:402 switch_core_session_run() (sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060) State RING
2007-07-24 17:04:13 [DEBUG] mod_sofia.c:120 sofia_on_ring() SOFIA RING
2007-07-24 17:04:13 [DEBUG] switch_core_state_machine.c:56 switch_core_standard_on_ring() Standard RING sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060
2007-07-24 17:04:13 [INFO] mod_dialplan_xml.c:316 dialplan_hunt() Processing key2->5399!
2007-07-24 17:04:13 [DEBUG] mod_dialplan_xml.c:116 parse_exten() test conditions destination_number(5399) =~ /^5391$/
2007-07-24 17:04:13 [DEBUG] mod_dialplan_xml.c:118 parse_exten() Regex mismatch
2007-07-24 17:04:13 [DEBUG] mod_dialplan_xml.c:116 parse_exten() test conditions destination_number(5399) =~ /^5390$/
2007-07-24 17:04:13 [DEBUG] mod_dialplan_xml.c:118 parse_exten() Regex mismatch
2007-07-24 17:04:13 [DEBUG] mod_dialplan_xml.c:116 parse_exten() test conditions destination_number(5399) =~ /^5399$/
2007-07-24 17:04:13 [DEBUG] mod_dialplan_xml.c:372 dialplan_hunt() sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 State Change CS_RING -> CS_EXECUTE
2007-07-24 17:04:13 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:04:13 [DEBUG] switch_core_state_machine.c:437 switch_core_session_run() (sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060) State EXECUTE
2007-07-24 17:04:13 [DEBUG] mod_sofia.c:137 sofia_on_execute() SOFIA EXECUTE
2007-07-24 17:04:13 [DEBUG] switch_core_state_machine.c:113 switch_core_standard_on_execute() Standard EXECUTE
2007-07-24 17:04:13 [NOTICE] switch_core_state_machine.c:123 switch_core_standard_on_execute() Execute answer()
2007-07-24 17:04:13 [DEBUG] sofia_glue.c:876 sofia_glue_activate_rtp() AUDIO RTP [sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060] 10.133.92.53:16386->10.60.2.20:45136 codec: 0 ms: 20
2007-07-24 17:04:13 [DEBUG] switch_rtp.c:538 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms
2007-07-24 17:04:13 [DEBUG] mod_sofia.c:317 sofia_answer_channel() Local SDP sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060:
v=0
o=FreeSWITCH 1185273067 1185273068 IN IP4 10.133.92.53
s=FreeSWITCH
c=IN IP4 10.133.92.53
t=0 0
a=sendrecv
m=audio 16386 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
nua: nua_respond: entering
nua(0x80c7cc0): signal r_respond
nua(0x80c7cc0): recv r_respond
nua(0x80c7cc0): signal r_respond 200 OK
nua: nua_stack_set_params: entering
soa_set_params(static::0x80ca310, ...) called
soa_set_user_sdp(static::0x80ca310, (nil), 0x80b9a6c, -1) called
soa_set_capability_sdp(static::0x80ca310, (nil), 0x80b9a6c, -1) called
nua: nua_invite_server_respond: entering
soa_generate_answer(static::0x80ca310) called
soa_static_offer_answer_action(0x80ca310, soa_generate_answer): called
soa_static(0x80ca310, soa_generate_answer): generating local description
soa_static(0x80ca310, soa_generate_answer): upgrade with remote description
soa_static(0x80ca310, soa_generate_answer): marking rejected media
soa_sdp_mode_set_is_needed(0x437c9104, 0x80c0190, ""): called
soa_static(0x80ca310, soa_generate_answer): storing local description
soa_activate(static::0x80ca310, (nil)) called
soa_get_local_sdp(static::0x80ca310, [(nil)], [0x437c9218], [0x437c9214]) called
tport_tsend(0x8091130) tpn = UDP/10.60.2.20:21778
tport_resolve addrinfo = 10.60.2.20:21778
tport_by_addrinfo(0x8091130): not found by name UDP/10.60.2.20:21778
tport_vsend(0x8091130): 914 bytes of 914 to UDP/10.60.2.20:21778
tport_vsend returned 914
send 914 bytes to udp/[10.60.2.20]:21778 at 15:04:13.252074:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-0c39062a9d626d65-1--d87543-
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=c1788339
To: "5399" <sip:5399@svidev06b.tst33.cvf>;tag=UgUc3e5c45BBp
Call-ID: ZmZjNTAxOWEwMWY2YThmMDhhYmYxMDllMzllZmRhNGE.
CSeq: 1 INVITE
Contact: <sip:mod_sofia@10.133.92.53:5060>
User-Agent: FreeSWITCH(mod_sofia)
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: 100rel, precondition
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 295
v=0
o=FreeSWITCH 1151807409329099377 5176940148824763350 IN IP4 10.133.92.53
s=FreeSWITCH
c=IN IP4 10.133.92.53
t=0 0
a=sendrecv
m=audio 16386 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
m=video 0 RTP/AVP 9
------------------------------------------------------------------------
nta: sent 200 OK for INVITE (1)
nua(0x80c7cc0): call state changed: received -> completed, sent answer
soa_get_local_sdp(static::0x80ca310, [0x437c9290], [0x437c928c], [(nil)]) called
soa_get_params(static::0x80ca310, ...) called
nua(0x80c7cc0): event i_state 200 OK
nua: nua_event: entering
2007-07-24 17:04:13 [DEBUG] sofia.c:1028 sofia_handle_sip_i_state() Channel sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 entering state [completed]
2007-07-24 17:04:13 [DEBUG] switch_core_session.c:349 switch_core_session_receive_message() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:04:13 [NOTICE] mod_dptools.c:286 answer_function() Channel [sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060] has been answered
2007-07-24 17:04:13 [NOTICE] switch_core_state_machine.c:123 switch_core_standard_on_execute() Execute sleep(1000)
nta: timer set next to 311 ms
tport_wakeup_pri(0x8091130): events IN
tport_recv_event(0x8091130)
tport_recv_iovec(0x8091130) msg 0x80c42d8 from (udp/10.133.92.53:5060) has 438 bytes, veclen = 1
recv 438 bytes from udp/[10.60.2.20]:21778 at 15:04:13.455802:
------------------------------------------------------------------------
ACK sip:mod_sofia@10.133.92.53:5060 SIP/2.0
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-7a6d3459233fa445-1--d87543-
Max-Forwards: 70
Contact: <sip:key2@10.60.2.20:21778>
To: "5399"<sip:5399@svidev06b.tst33.cvf>;tag=UgUc3e5c45BBp
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=c1788339
Call-ID: ZmZjNTAxOWEwMWY2YThmMDhhYmYxMDllMzllZmRhNGE.
CSeq: 1 ACK
User-Agent: X-Lite release 1011s stamp 41150
Content-Length: 0
------------------------------------------------------------------------
tport_deliver(0x8091130): msg 0x80c42d8 (438 bytes) from udp/10.60.2.20:5060/sip next=(nil)
nta: received ACK sip:mod_sofia@10.133.92.53:5060 SIP/2.0 (CSeq 1)
nta: ACK (1) is going to INVITE (1)
nua: process_ack_or_cancel: entering
soa_clear_remote_sdp(static::0x80ca310) called
nua(0x80c7cc0): event i_ack 200 OK
nua(0x80c7cc0): call state changed: completed -> ready
nua(0x80c7cc0): event i_state 200 OK
nua(0x80c7cc0): event i_active 200 Call active
nua: nua_event: entering
nua: nua_event: entering
nua: nua_event: entering
2007-07-24 17:04:13 [DEBUG] sofia.c:1028 sofia_handle_sip_i_state() Channel sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 entering state [ready]
nta: timer set next to 4703 ms
2007-07-24 17:04:14 [NOTICE] switch_core_state_machine.c:123 switch_core_standard_on_execute() Execute bridge(openzap/1/0/0614062706)
nta: timer I fired, terminate 200 response
incoming_reclaim_all((nil), (nil), 0x437c9208)
nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer not set