[Freeswitch-users] T38 fax. FS fails after reINVITE

Vladimir Getmanshchuk vladget at gmail.com
Tue Jun 10 20:35:46 MSD 2014


Hi Michel,

It works great with:

    <param name="t38-passthru" value="true"/>

at sofia.conf.xml.

Got 200 OK on reINVITE.

Should I open ticket in JIRA?


On Tue, Jun 10, 2014 at 8:26 AM, Michael Jerris <mike at jerris.com> wrote:

> Would you like to do t.38 passthrough?
>
> https://wiki.freeswitch.org/wiki/T.38#Sofia_profile_parameters
>
>
> That being said, this seems like a bug.  Regardless of how its configured,
> we should never just not respond to the re-invite.  Please test a bit with
> those settings be file a jira in regards to this lack of reply to invite.
>
> On Jun 10, 2014, at 3:09 PM, Vladimir Getmanshchuk <vladget at gmail.com>
> wrote:
>
> Hi Mike,
>
> Have you seen my freeswitch debug trace?
>
>
> On Wed, Jun 4, 2014 at 8:17 PM, Vladimir Getmanshchuk <vladget at gmail.com>
> wrote:
>
>> here is the link wth zipped trace:
>>
>> https://drive.google.com/file/d/0BwhSFyzHYCE-LUdVaVVTOEhUOFU/edit?usp=sharing
>>
>>
>> On Tue, Jun 3, 2014 at 12:59 PM, Vladimir Getmanshchuk <vladget at gmail.com
>> > wrote:
>>
>>> Your pastebin server returned: "Query failure: Got a packet bigger than
>>> 'max_allowed_packet' bytes", so log attached.
>>> And this mail list looks like does not receive emails with large
>>> attachments..
>>>
>>> Please advice how I can provide the trace.
>>>
>>> Thanks!
>>>
>>>
>>>  On Mon, Jun 2, 2014 at 5:48 AM, Michael Jerris <mike at jerris.com> wrote:
>>>
>>>>  Is there any freeswitch debug that goes along with this?  The sofia
>>>> trace is helpful, the sofia debug, not as much, and the freeswitch debug
>>>> would probably be helpful as well.
>>>>
>>>>
>>>> On Jun 1, 2014, at 4:32 AM, Vladimir Getmanshchuk <vladget at gmail.com>
>>>> wrote:
>>>>
>>>>  I've tested faxes with FS 1.4.5. And still got no success.
>>>> FS(fax originator)  ---> tested FS ----> SWITCH WHAT SUPPORT T38.
>>>>
>>>> FS reply 100 trying after reINVITE and that's it, but should answer
>>>> with 200 OK..
>>>> Please advice how to get it work.
>>>>
>>>> my sip trace and sofia trace:
>>>>
>>>> recv 1016 bytes from udp/[11.11.11.11]:5080 at 23:41:30.861560:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    INVITE sip:2222222222 at 22.22.22.22:5070 SIP/2.0
>>>>    Via: SIP/2.0/UDP 11.11.11.11:5080;rport;branch=z9hG4bKNpj7NtK5yQjyQ
>>>>    Max-Forwards: 70
>>>>    From: "+111111111111" <sip:+111111111111 at 11.11.11.11
>>>> >;tag=H53g29BtQBSKj
>>>>    To: <sip:2222222222 at 22.22.22.22:5070>
>>>>    Call-ID: eeda303b-63bf-1232-feb0-f2eff32e29d0
>>>>    CSeq: 60453781 INVITE
>>>>    Contact: <sip:mod_sofia at 11.11.11.11:5080>
>>>>    User-Agent: FS
>>>>    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>>>> REGISTER, REFER, NOTIFY
>>>>    Supported: timer, path, replaces
>>>>    Allow-Events: talk, hold, conference, refer
>>>>    Content-Type: application/sdp
>>>>    Content-Disposition: session
>>>>    Content-Length: 225
>>>>    X-FS-Support: update_display,send_info
>>>>    Remote-Party-ID: "+111111111111" <sip:+111111111111 at 11.11.11.11
>>>> >;party=calling;screen=yes;privacy=off
>>>>
>>>>    v=0
>>>>    o=FreeSWITCH 1401562482 1401562483 IN IP4 11.11.11.11
>>>>    s=FreeSWITCH
>>>>    c=IN IP4 11.11.11.11
>>>>    t=0 0
>>>>    m=audio 17208 RTP/AVP 8 101 13
>>>>    a=rtpmap:8 PCMA/8000
>>>>    a=rtpmap:101 telephone-event/8000
>>>>    a=fmtp:101 0-16
>>>>    a=ptime:20
>>>>
>>>>  ------------------------------------------------------------------------
>>>>  tport.c:3023 tport_deliver() tport_deliver(0x1d12180): msg 0x1ca3590
>>>> (1016 bytes) from udp/11.11.11.11:5070/sip next=(nil)
>>>> nta.c:2880 agent_recv_request() nta: received INVITE
>>>> sip:2222222222 at 22.22.22.22:5070 SIP/2.0 (CSeq 60453781)
>>>> nta.c:3246 agent_aliases() nta: canonizing
>>>> sip:2222222222 at 22.22.22.22:5070 with contact
>>>> nta.c:3085 agent_recv_request() nta: INVITE (60453781) going to a
>>>> default leg
>>>> nta.c:1350 set_timeout() nta: timer set to 200 ms
>>>> nua_server.c:102 nua_stack_process_request() nua:
>>>> nua_stack_process_request: entering
>>>> nua_stack.c:899 nh_create() nua: nh_create: entering
>>>> nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
>>>> nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params:
>>>> entering
>>>> soa.c:280 soa_clone() soa_clone(static::0x1d0fd90, 0x1cb0640,
>>>> 0x1d39800) called
>>>> soa.c:403 soa_set_params() soa_set_params(static::0x1d17170, ...) called
>>>> nta.c:4415 nta_leg_tcreate() nta_leg_tcreate(0x1d17950)
>>>> soa.c:1302 soa_init_offer_answer()
>>>> soa_init_offer_answer(static::0x1d17170) called
>>>> soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x1d17170,
>>>> (nil), 0x1d13e67, 225) called
>>>> nua_dialog.c:338 nua_dialog_usage_add() nua(0x1d39800): adding session
>>>> usage
>>>> tport.c:3257 tport_tsend() tport_tsend(0x1d12180) tpn = UDP/
>>>> 11.11.11.11:5080
>>>> tport.c:4046 tport_resolve() tport_resolve addrinfo = 11.11.11.11:5080
>>>> tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x1d12180): not
>>>> found by name UDP/11.11.11.11:5080
>>>> tport.c:3594 tport_vsend() tport_vsend(0x1d12180): 324 bytes of 324 to
>>>> udp/11.11.11.11:5080
>>>> tport.c:3492 tport_send_msg() tport_vsend returned 324
>>>> send 324 bytes to udp/[11.11.11.11]:5080 at 23:41:30.862101:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    SIP/2.0 100 Trying
>>>>    Via: SIP/2.0/UDP 11.11.11.11:5080
>>>> ;rport=5080;branch=z9hG4bKNpj7NtK5yQjyQ
>>>>    From: "+111111111111" <sip:+111111111111 at 11.11.11.11
>>>> >;tag=H53g29BtQBSKj
>>>>    To: <sip:2222222222 at 22.22.22.22:5070>
>>>>    Call-ID: eeda303b-63bf-1232-feb0-f2eff32e29d0
>>>>    CSeq: 60453781 INVITE
>>>>    User-Agent: FS
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> nta.c:6789 incoming_reply() nta: sent 100 Trying for INVITE (60453781)
>>>> nua_stack.c:271 nua_stack_event() nua(0x1d39800): event i_invite 100
>>>> Trying
>>>> nua_session.c:4137 signal_call_state_change() nua(0x1d39800): call
>>>> state changed: init -> received, received offer
>>>> soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x1d17170,
>>>> [0x7f5303ffe598], [0x7f5303ffe5a0], [(nil)]) called
>>>> nua_stack.c:271 nua_stack_event() nua(0x1d39800): event i_state 100
>>>> Trying
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
>>>>  nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
>>>> nua.c:633 nua_invite() nua: nua_invite: entering
>>>> nua_stack.c:529 nua_signal() nua(0x7f53700147d0): sent signal r_invite
>>>> nua_stack.c:569 nua_stack_signal() nua(0x7f53700147d0): recv signal
>>>> r_invite
>>>> nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params:
>>>> entering
>>>> soa.c:280 soa_clone() soa_clone(static::0x7f5334001930, 0x7f5334001130,
>>>> 0x7f53700147d0) called
>>>> soa.c:403 soa_set_params() soa_set_params(static::0x7f533401eed0, ...)
>>>> called
>>>> soa.c:403 soa_set_params() soa_set_params(static::0x7f533401eed0, ...)
>>>> called
>>>> soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f533401eed0,
>>>> (nil), 0x7f53700123f3, -1) called
>>>> soa.c:890 soa_set_capability_sdp()
>>>> soa_set_capability_sdp(static::0x7f533401eed0, (nil), 0x7f53700123f3, -1)
>>>> called
>>>> nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f53700147d0): adding
>>>> session usage
>>>> nta.c:4415 nta_leg_tcreate() nta_leg_tcreate(0x7f5334018320)
>>>> soa.c:1302 soa_init_offer_answer()
>>>> soa_init_offer_answer(static::0x7f533401eed0) called
>>>> soa.c:1426 soa_generate_offer()
>>>> soa_generate_offer(static::0x7f533401eed0, 0) called
>>>> soa_static.c:1137 offer_answer_step()
>>>> soa_static_offer_answer_action(0x7f533401eed0, soa_generate_offer): called
>>>> soa_static.c:1168 offer_answer_step() soa_static(0x7f533401eed0,
>>>> soa_generate_offer): generating local description
>>>> soa_static.c:1196 offer_answer_step() soa_static(0x7f533401eed0,
>>>> soa_generate_offer): upgrade with local description
>>>> soa_static.c:1020 soa_sdp_mode_set() soa_sdp_mode_set(0x7f537d8139d0,
>>>> (nil), ""): called
>>>> soa_static.c:1425 offer_answer_step() soa_static(0x7f533401eed0,
>>>> soa_generate_offer): storing local description
>>>> soa.c:1270 soa_get_local_sdp()
>>>> soa_get_local_sdp(static::0x7f533401eed0, [(nil)], [0x7f537d813b40],
>>>> [0x7f537d813b4c]) called
>>>> nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
>>>> tport.c:3257 tport_tsend() tport_tsend(0x7f5334004450) tpn = UDP/
>>>> 33.33.33.33:5060
>>>> tport.c:4046 tport_resolve() tport_resolve addrinfo = 33.33.33.33:5060
>>>> tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f5334004450): not
>>>> found by name UDP/33.33.33.33:5060
>>>> tport.c:3594 tport_vsend() tport_vsend(0x7f5334004450): 1010 bytes of
>>>> 1010 to udp/33.33.33.33:5060
>>>> tport.c:3492 tport_send_msg() tport_vsend returned 1010
>>>> send 1010 bytes to udp/[33.33.33.33]:5060 at 23:41:30.865276:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    INVITE sip:002222222222 at 33.33.33.33 SIP/2.0
>>>>    Via: SIP/2.0/UDP 22.22.22.22:5080;rport;branch=z9hG4bKX94Z74KNte97S
>>>>    Max-Forwards: 69
>>>>    From: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    To: <sip:002222222222 at 33.33.33.33>
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>    CSeq: 60453781 INVITE
>>>>    Contact: <sip:mod_sofia at 22.22.22.22:5080>
>>>>    User-Agent: FS
>>>>    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>>>> REGISTER, REFER, NOTIFY
>>>>    Supported: timer, path, replaces
>>>>    Allow-Events: talk, hold, conference, refer
>>>>    Content-Type: application/sdp
>>>>    Content-Disposition: session
>>>>    Content-Length: 225
>>>>    X-FS-Support: update_display,send_info
>>>>    Remote-Party-ID: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;party=calling;screen=yes;privacy=off
>>>>
>>>>    v=0
>>>>    o=FreeSWITCH 1401556470 1401556471 IN IP4 22.22.22.22
>>>>    s=FreeSWITCH
>>>>    c=IN IP4 22.22.22.22
>>>>    t=0 0
>>>>    m=audio 23220 RTP/AVP 8 101 13
>>>>    a=rtpmap:8 PCMA/8000
>>>>    a=rtpmap:101 telephone-event/8000
>>>>    a=fmtp:101 0-16
>>>>    a=ptime:20
>>>>
>>>>  ------------------------------------------------------------------------
>>>>  nta.c:8302 outgoing_send() nta: sent INVITE (60453781) to UDP/
>>>> 33.33.33.33:5060
>>>> tport.c:4160 tport_pend() tport_pend(0x7f5334004450): pending
>>>> 0x7f5334029a40 for udp/22.22.22.22:5080 (already 0)
>>>> nta.c:1350 set_timeout() nta: timer set to 32000 ms
>>>> nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
>>>> nua_session.c:4137 signal_call_state_change() nua(0x7f53700147d0): call
>>>> state changed: init -> calling, sent offer
>>>> soa.c:1270 soa_get_local_sdp()
>>>> soa_get_local_sdp(static::0x7f533401eed0, [0x7f537d813b38],
>>>> [0x7f537d813b40], [(nil)]) called
>>>> nua_stack.c:269 nua_stack_event() nua(0x7f53700147d0): event i_state
>>>> INVITE sent
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f5334004450):
>>>> events IN
>>>> tport.c:2864 tport_recv_event() tport_recv_event(0x7f5334004450)
>>>> tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f5334004450) msg
>>>> 0x7f533402d0d0 from (udp/22.22.22.22:5080) has 325 bytes, veclen = 1
>>>> recv 325 bytes from udp/[33.33.33.33]:5060 at 23:41:30.883443:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    SIP/2.0 100 Trying
>>>>    Via: SIP/2.0/UDP 22.22.22.22:5080
>>>> ;rport=5080;received=22.22.22.22;branch=z9hG4bKX94Z74KNte97S
>>>>    From: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    To: <sip:002222222222 at 33.33.33.33>
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>    CSeq: 60453781 INVITE
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> tport.c:3023 tport_deliver() tport_deliver(0x7f5334004450): msg
>>>> 0x7f533402d0d0 (325 bytes) from udp/33.33.33.33:5080/sip next=(nil)
>>>> nta.c:3297 agent_recv_response() nta: received 100 Trying for INVITE
>>>> (60453781)
>>>> nta.c:3364 agent_recv_response() nta: 100 Trying is going to a
>>>> transaction
>>>> nta.c:9562 outgoing_estimate_delay() nta_outgoing: RTT is 18.27 ms
>>>> tport.c:4222 tport_release() tport_release(0x7f5334004450):
>>>> 0x7f5334029a40 by 0x7f533402abd0 with 0x7f533402d0d0 (preliminary)
>>>> nta.c:1289 agent_timer() nta: timer not set
>>>> tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f5334004450):
>>>> events IN
>>>> tport.c:2864 tport_recv_event() tport_recv_event(0x7f5334004450)
>>>> tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f5334004450) msg
>>>> 0x7f533402c260 from (udp/22.22.22.22:5080) has 827 bytes, veclen = 1
>>>> recv 827 bytes from udp/[33.33.33.33]:5060 at 23:41:31.808643:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    SIP/2.0 183 Session Progress
>>>>    Via: SIP/2.0/UDP 22.22.22.22:5080
>>>> ;rport=5080;received=22.22.22.22;branch=z9hG4bKX94Z74KNte97S
>>>>    To: <sip:002222222222 at 33.33.33.33>;tag=3610568491-801417
>>>>    From: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>    CSeq: 60453781 INVITE
>>>>    Allow: UPDATE,PRACK,INFO,OPTIONS,BYE,INVITE,ACK,CANCEL
>>>>    Contact: <sip:002222222222 at 33.33.33.33:5060>
>>>>    Content-Type: application/sdp
>>>>    Accept: application/sdp
>>>>    Content-Length: 306
>>>>
>>>>    v=0
>>>>    o=sbc-uk-bm-th02b 372172800 1401579692 IN IP4 33.33.33.33
>>>>    s=sip call
>>>>    c=IN IP4 33.33.33.34
>>>>    t=0 0
>>>>    m=audio 43554 RTP/AVP 8 101
>>>>    a=sendrecv
>>>>    a=rtpmap:8 PCMA/8000
>>>>    a=rtpmap:101 telephone-event/8000
>>>>    a=fmtp:101 0-15
>>>>    a=silenceSupp:off
>>>>    a=ptime:20
>>>>    a=maxptime:30
>>>>    a=sqn: 0
>>>>    a=cdsc:1 image udptl t38
>>>>
>>>>  ------------------------------------------------------------------------
>>>> tport.c:3023 tport_deliver() tport_deliver(0x7f5334004450): msg
>>>> 0x7f533402c260 (827 bytes) from udp/33.33.33.33:5080/sip next=(nil)
>>>> nta.c:3297 agent_recv_response() nta: received 183 Session Progress for
>>>> INVITE (60453781)
>>>> nta.c:3364 agent_recv_response() nta: 183 Session Progress is going to
>>>> a transaction
>>>> tport.c:4222 tport_release() tport_release(0x7f5334004450):
>>>> 0x7f5334029a40 by 0x7f533402abd0 with 0x7f533402c260 (preliminary)
>>>> soa.c:1171 soa_set_remote_sdp()
>>>> soa_set_remote_sdp(static::0x7f533401eed0, (nil), 0x7f533402ca59, 306)
>>>> called
>>>> soa.c:1595 soa_process_answer()
>>>> soa_process_answer(static::0x7f533401eed0) called
>>>> soa_static.c:1137 offer_answer_step()
>>>> soa_static_offer_answer_action(0x7f533401eed0, soa_process_answer): called
>>>> soa_static.c:1020 soa_sdp_mode_set() soa_sdp_mode_set(0x7f533402ade0,
>>>> 0x7f5334030a90, ""): called
>>>> soa_static.c:1283 offer_answer_step() soa_static(0x7f533401eed0,
>>>> soa_process_answer): upgrade codecs with remote description
>>>> soa.c:1730 soa_activate() soa_activate(static::0x7f533401eed0, (nil))
>>>> called
>>>> nua_session.c:988 nua_session_client_response() nua(0x7f53700147d0):
>>>> INVITE: processed SDP answer in 183 Session Progress
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event r_invite
>>>> 183 Session Progress
>>>> nua_session.c:4137 signal_call_state_change() nua(0x7f53700147d0): call
>>>> state changed: calling -> proceeding, received answer
>>>> soa.c:1098 soa_get_remote_sdp()
>>>> soa_get_remote_sdp(static::0x7f533401eed0, [0x7f537d8132d8],
>>>> [0x7f537d8132e0], [(nil)]) called
>>>> soa.c:616 soa_get_params() soa_get_params(static::0x7f533401eed0, ...)
>>>> called
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event i_state
>>>> 183 Session Progress
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:879 nua_respond() nua: nua_respond: entering
>>>> nua_stack.c:529 nua_signal() nua(0x1d39800): sent signal r_respond
>>>> nua_stack.c:573 nua_stack_signal() nua(0x1d39800): recv signal
>>>> r_respond 183 Session Progress
>>>> nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params:
>>>> entering
>>>> soa.c:403 soa_set_params() soa_set_params(static::0x1d17170, ...) called
>>>> soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x1d17170,
>>>> (nil), 0x7f5374009b02, -1) called
>>>> soa.c:890 soa_set_capability_sdp()
>>>> soa_set_capability_sdp(static::0x1d17170, (nil), 0x7f5374009b02, -1) called
>>>> nua_session.c:2318 nua_invite_server_respond() nua:
>>>> nua_invite_server_respond: entering
>>>> soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x1d17170)
>>>> called
>>>> soa_static.c:1137 offer_answer_step()
>>>> soa_static_offer_answer_action(0x1d17170, soa_generate_answer): called
>>>> soa_static.c:1168 offer_answer_step() soa_static(0x1d17170,
>>>> soa_generate_answer): generating local description
>>>> soa_static.c:1209 offer_answer_step() soa_static(0x1d17170,
>>>> soa_generate_answer): upgrade with remote description
>>>> soa_static.c:1020 soa_sdp_mode_set() soa_sdp_mode_set(0x7f5303ffea40,
>>>> 0x1ca2550, ""): called
>>>> soa_static.c:1425 offer_answer_step() soa_static(0x1d17170,
>>>> soa_generate_answer): storing local description
>>>> soa.c:1730 soa_activate() soa_activate(static::0x1d17170, (nil)) called
>>>> soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x1d17170,
>>>> [(nil)], [0x7f5303ffebb0], [0x7f5303ffebbc]) called
>>>> tport.c:3257 tport_tsend() tport_tsend(0x1d12180) tpn = UDP/
>>>> 11.11.11.11:5080
>>>> tport.c:4046 tport_resolve() tport_resolve addrinfo = 11.11.11.11:5080
>>>> tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x1d12180): not
>>>> found by name UDP/11.11.11.11:5080
>>>> tport.c:3594 tport_vsend() tport_vsend(0x1d12180): 1137 bytes of 1137
>>>> to udp/11.11.11.11:5080
>>>> tport.c:3492 tport_send_msg() tport_vsend returned 1137
>>>> send 1137 bytes to udp/[11.11.11.11]:5080 at 23:41:31.832193:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    SIP/2.0 183 Session Progress
>>>>    Via: SIP/2.0/UDP 11.11.11.11:5080
>>>> ;rport=5080;branch=z9hG4bKNpj7NtK5yQjyQ
>>>>    From: "+111111111111" <sip:+111111111111 at 11.11.11.11
>>>> >;tag=H53g29BtQBSKj
>>>>    To: <sip:2222222222 at 22.22.22.22:5070>;tag=rZg31jSXgjK5r
>>>>    Call-ID: eeda303b-63bf-1232-feb0-f2eff32e29d0
>>>>    CSeq: 60453781 INVITE
>>>>    Contact: <sip:2222222222 at 22.22.22.22:5070;transport=udp>
>>>>    User-Agent: FS
>>>>    Accept: application/sdp
>>>>    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>>>> NOTIFY
>>>>    Supported: timer, path, replaces
>>>>    Allow-Events: talk, hold, conference, refer
>>>>    Content-Type: application/sdp
>>>>    Content-Disposition: session
>>>>    Content-Length: 249
>>>>    X-FS-Display-Name: Outbound Call
>>>>    X-FS-Display-Number: sip:002222222222 at 22.22.22.22
>>>>    X-FS-Support: update_display,send_info
>>>>    Remote-Party-ID: "Outbound Call" <sip:002222222222 at 22.22.22.22
>>>> >;party=calling;privacy=off;screen=no
>>>>
>>>>    v=0
>>>>    o=FreeSWITCH 1401550453 1401550454 IN IP4 22.22.22.22
>>>>    s=FreeSWITCH
>>>>    c=IN IP4 22.22.22.22
>>>>    t=0 0
>>>>    m=audio 29238 RTP/AVP 8 101
>>>>    a=rtpmap:8 PCMA/8000
>>>>    a=rtpmap:101 telephone-event/8000
>>>>    a=fmtp:101 0-16
>>>>    a=silenceSupp:off - - - -
>>>>    a=ptime:20
>>>>
>>>>  ------------------------------------------------------------------------
>>>> nta.c:6789 incoming_reply() nta: sent 183 Session Progress for INVITE
>>>> (60453781)
>>>> nta.c:1350 set_timeout() nta: timer set to 60000 ms
>>>> nua_session.c:4137 signal_call_state_change() nua(0x1d39800): call
>>>> state changed: received -> early, sent answer
>>>> soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x1d17170,
>>>> [0x7f5303ffeca8], [0x7f5303ffecb0], [(nil)]) called
>>>> soa.c:616 soa_get_params() soa_get_params(static::0x1d17170, ...) called
>>>> nua_stack.c:271 nua_stack_event() nua(0x1d39800): event i_state 183
>>>> Session Progress
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nta.c:1289 agent_timer() nta: timer not set
>>>> tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f5334004450):
>>>> events IN
>>>> tport.c:2864 tport_recv_event() tport_recv_event(0x7f5334004450)
>>>> tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f5334004450) msg
>>>> 0x7f533402d180 from (udp/22.22.22.22:5080) has 818 bytes, veclen = 1
>>>> recv 818 bytes from udp/[33.33.33.33]:5060 at 23:41:32.714486:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    SIP/2.0 180 Ringing
>>>>    Via: SIP/2.0/UDP 22.22.22.22:5080
>>>> ;rport=5080;received=22.22.22.22;branch=z9hG4bKX94Z74KNte97S
>>>>    To: <sip:002222222222 at 33.33.33.33>;tag=3610568491-801417
>>>>    From: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>    CSeq: 60453781 INVITE
>>>>    Allow: UPDATE,PRACK,INFO,OPTIONS,BYE,INVITE,ACK,CANCEL
>>>>    Contact: <sip:002222222222 at 33.33.33.33:5060>
>>>>    Content-Type: application/sdp
>>>>    Accept: application/sdp
>>>>    Content-Length: 306
>>>>
>>>>    v=0
>>>>    o=sbc-uk-bm-th02b 372172800 1401579692 IN IP4 33.33.33.33
>>>>    s=sip call
>>>>    c=IN IP4 33.33.33.34
>>>>    t=0 0
>>>>    m=audio 43554 RTP/AVP 8 101
>>>>    a=sendrecv
>>>>    a=rtpmap:8 PCMA/8000
>>>>    a=rtpmap:101 telephone-event/8000
>>>>    a=fmtp:101 0-15
>>>>    a=silenceSupp:off
>>>>    a=ptime:20
>>>>    a=maxptime:30
>>>>    a=sqn: 0
>>>>    a=cdsc:1 image udptl t38
>>>>
>>>>  ------------------------------------------------------------------------
>>>> tport.c:3023 tport_deliver() tport_deliver(0x7f5334004450): msg
>>>> 0x7f533402d180 (818 bytes) from udp/33.33.33.33:5080/sip next=(nil)
>>>> nta.c:3297 agent_recv_response() nta: received 180 Ringing for INVITE
>>>> (60453781)
>>>> nta.c:3364 agent_recv_response() nta: 180 Ringing is going to a
>>>> transaction
>>>> tport.c:4222 tport_release() tport_release(0x7f5334004450):
>>>> 0x7f5334029a40 by 0x7f533402abd0 with 0x7f533402d180 (preliminary)
>>>> soa.c:1171 soa_set_remote_sdp()
>>>> soa_set_remote_sdp(static::0x7f533401eed0, (nil), 0x7f533402e600, 306)
>>>> called
>>>> soa.c:1595 soa_process_answer()
>>>> soa_process_answer(static::0x7f533401eed0) called
>>>> nua_session.c:978 nua_session_client_response() nua(0x7f53700147d0):
>>>> INVITE: error processing SDP answer in 180 Ringing
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event r_invite
>>>> 180 Ringing
>>>> nua_session.c:4137 signal_call_state_change() nua(0x7f53700147d0): call
>>>> state changed: proceeding -> proceeding, received answer
>>>> soa.c:1098 soa_get_remote_sdp()
>>>> soa_get_remote_sdp(static::0x7f533401eed0, [0x7f537d813418],
>>>> [0x7f537d813420], [(nil)]) called
>>>> soa.c:616 soa_get_params() soa_get_params(static::0x7f533401eed0, ...)
>>>> called
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event i_state
>>>> 180 Ringing
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f5334004450):
>>>> events IN
>>>> tport.c:2864 tport_recv_event() tport_recv_event(0x7f5334004450)
>>>> tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f5334004450) msg
>>>> 0x7f533402f8d0 from (udp/22.22.22.22:5080) has 844 bytes, veclen = 1
>>>> recv 844 bytes from udp/[33.33.33.33]:5060 at 23:41:33.964863:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    SIP/2.0 200 OK
>>>>    Session-Expires: 3600;refresher=uas
>>>>    Require: timer
>>>>    Via: SIP/2.0/UDP 22.22.22.22:5080
>>>> ;rport=5080;received=22.22.22.22;branch=z9hG4bKX94Z74KNte97S
>>>>    To: <sip:002222222222 at 33.33.33.33>;tag=3610568491-801417
>>>>    From: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>     CSeq: 60453781 INVITE
>>>>    Allow: UPDATE,PRACK,INFO,OPTIONS,BYE,INVITE,ACK,CANCEL
>>>>    Contact: <sip:002222222222 at 33.33.33.33:5060>
>>>>    Content-Type: application/sdp
>>>>    Accept: application/sdp
>>>>    Content-Length: 284
>>>>
>>>>    v=0
>>>>    o=sbc-uk-bm-th02b 372172800 1401579693 IN IP4 33.33.33.33
>>>>    s=sip call
>>>>    c=IN IP4 33.33.33.34
>>>>    t=0 0
>>>>    m=audio 43554 RTP/AVP 8 101
>>>>    a=rtpmap:8 PCMA/8000
>>>>    a=rtpmap:101 telephone-event/8000
>>>>    a=fmtp:101 0-15
>>>>    a=silenceSupp:off
>>>>    a=ptime:20
>>>>    a=maxptime:30
>>>>    a=cdsc:1 image udptl t38
>>>>
>>>>  ------------------------------------------------------------------------
>>>> tport.c:3023 tport_deliver() tport_deliver(0x7f5334004450): msg
>>>> 0x7f533402f8d0 (844 bytes) from udp/33.33.33.33:5080/sip next=(nil)
>>>> nta.c:3297 agent_recv_response() nta: received 200 OK for INVITE
>>>> (60453781)
>>>> nta.c:3364 agent_recv_response() nta: 200 OK is going to a transaction
>>>> tport.c:4222 tport_release() tport_release(0x7f5334004450):
>>>> 0x7f5334029a40 by 0x7f533402abd0 with 0x7f533402f8d0
>>>> nta.c:1350 set_timeout() nta: timer set to 32000 ms
>>>> nua_dialog.c:564 nua_dialog_usage_set_refresh_range() nua(): refresh
>>>> session after 1805 seconds (in [1795..1805])
>>>> soa.c:1171 soa_set_remote_sdp()
>>>> soa_set_remote_sdp(static::0x7f533401eed0, (nil), 0x7f533402eab0, 284)
>>>> called
>>>> soa.c:1595 soa_process_answer()
>>>> soa_process_answer(static::0x7f533401eed0) called
>>>> nua_session.c:978 nua_session_client_response() nua(0x7f53700147d0):
>>>> INVITE: error processing SDP answer in 200 OK
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event r_invite
>>>> 200 OK
>>>> nua_session.c:4137 signal_call_state_change() nua(0x7f53700147d0): call
>>>> state changed: proceeding -> completing, received answer
>>>> soa.c:1098 soa_get_remote_sdp()
>>>> soa_get_remote_sdp(static::0x7f533401eed0, [0x7f537d813418],
>>>> [0x7f537d813420], [(nil)]) called
>>>> soa.c:616 soa_get_params() soa_get_params(static::0x7f533401eed0, ...)
>>>> called
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event i_state
>>>> 200 OK
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:639 nua_ack() nua: nua_ack: entering
>>>> nua_stack.c:569 nua_stack_signal() nua(0x7f53700147d0): recv signal
>>>> r_ack
>>>> nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params:
>>>> entering
>>>> soa.c:403 soa_set_params() soa_set_params(static::0x7f533401eed0, ...)
>>>> called
>>>> soa.c:1730 soa_activate() soa_activate(static::0x7f533401eed0, (nil))
>>>> called
>>>> nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
>>>> nua_stack.c:529 nua_signal() nua(0x7f53700147d0): sent signal r_ack
>>>> tport.c:3257 tport_tsend() tport_tsend(0x7f5334004450) tpn = UDP/
>>>> 33.33.33.33:5060
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> tport.c:4046 tport_resolve() tport_resolve addrinfo = 33.33.33.33:5060
>>>> tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f5334004450): not
>>>> found by name UDP/33.33.33.33:5060
>>>> tport.c:3594 tport_vsend() tport_vsend(0x7f5334004450): 410 bytes of
>>>> 410 to udp/33.33.33.33:5060
>>>> tport.c:3492 tport_send_msg() tport_vsend returned 410
>>>> send 410 bytes to udp/[33.33.33.33]:5060 at 23:41:33.965993:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    ACK sip:002222222222 at 33.33.33.33:5060 SIP/2.0
>>>>    Via: SIP/2.0/UDP 22.22.22.22:5080;rport;branch=z9hG4bKyjyr9Z4rQQZtN
>>>>    Max-Forwards: 70
>>>>    From: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    To: <sip:002222222222 at 33.33.33.33>;tag=3610568491-801417
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>    CSeq: 60453781 ACK
>>>>    Contact: <sip:mod_sofia at 22.22.22.22:5080>
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> nta.c:8302 outgoing_send() nta: sent ACK (60453781) to UDP/
>>>> 33.33.33.33:5060
>>>> nua_session.c:4137 signal_call_state_change() nua(0x7f53700147d0): call
>>>> state changed: completing -> ready
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event i_state
>>>> 200 ACK sent
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event i_active
>>>> 200 Call active
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:879 nua_respond() nua: nua_respond: entering
>>>> nua_stack.c:529 nua_signal() nua(0x1d39800): sent signal r_respond
>>>> nua_stack.c:573 nua_stack_signal() nua(0x1d39800): recv signal
>>>> r_respond 200 OK
>>>> nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params:
>>>> entering
>>>> soa.c:403 soa_set_params() soa_set_params(static::0x1d17170, ...) called
>>>> soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x1d17170,
>>>> (nil), 0x7f53740265e4, -1) called
>>>> nua_session.c:2318 nua_invite_server_respond() nua:
>>>> nua_invite_server_respond: entering
>>>> soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x1d17170,
>>>> [(nil)], [0x7f5303ffebb0], [0x7f5303ffebbc]) called
>>>> tport.c:3257 tport_tsend() tport_tsend(0x1d12180) tpn = UDP/
>>>> 11.11.11.11:5080
>>>> tport.c:4046 tport_resolve() tport_resolve addrinfo = 11.11.11.11:5080
>>>> tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x1d12180): not
>>>> found by name UDP/11.11.11.11:5080
>>>> tport.c:3594 tport_vsend() tport_vsend(0x1d12180): 1098 bytes of 1098
>>>> to udp/11.11.11.11:5080
>>>> tport.c:3492 tport_send_msg() tport_vsend returned 1098
>>>> send 1098 bytes to udp/[11.11.11.11]:5080 at 23:41:33.970944:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    SIP/2.0 200 OK
>>>>    Via: SIP/2.0/UDP 11.11.11.11:5080
>>>> ;rport=5080;branch=z9hG4bKNpj7NtK5yQjyQ
>>>>    From: "+111111111111" <sip:+111111111111 at 11.11.11.11
>>>> >;tag=H53g29BtQBSKj
>>>>    To: <sip:2222222222 at 22.22.22.22:5070>;tag=rZg31jSXgjK5r
>>>>    Call-ID: eeda303b-63bf-1232-feb0-f2eff32e29d0
>>>>    CSeq: 60453781 INVITE
>>>>    Contact: <sip:2222222222 at 22.22.22.22:5070;transport=udp>
>>>>    User-Agent: FS
>>>>    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>>>> NOTIFY
>>>>    Supported: timer, path, replaces
>>>>    Allow-Events: talk, hold, conference, refer
>>>>    Content-Type: application/sdp
>>>>    Content-Disposition: session
>>>>    Content-Length: 249
>>>>    X-FS-Display-Name: Outbound Call
>>>>    X-FS-Display-Number: sip:002222222222 at 22.22.22.22
>>>>    X-FS-Support: update_display,send_info
>>>>    Remote-Party-ID: "Outbound Call" <sip:002222222222 at 22.22.22.22
>>>> >;party=calling;privacy=off;screen=no
>>>>
>>>>    v=0
>>>>    o=FreeSWITCH 1401550453 1401550454 IN IP4 22.22.22.22
>>>>    s=FreeSWITCH
>>>>    c=IN IP4 22.22.22.22
>>>>    t=0 0
>>>>    m=audio 29238 RTP/AVP 8 101
>>>>    a=rtpmap:8 PCMA/8000
>>>>    a=rtpmap:101 telephone-event/8000
>>>>    a=fmtp:101 0-16
>>>>    a=silenceSupp:off - - - -
>>>>    a=ptime:20
>>>>
>>>>  ------------------------------------------------------------------------
>>>> nta.c:6789 incoming_reply() nta: sent 200 OK for INVITE (60453781)
>>>> nta.c:1348 set_timeout() nta: timer shortened to 500 ms
>>>> nua_session.c:4137 signal_call_state_change() nua(0x1d39800): call
>>>> state changed: early -> completed, sent answer
>>>> soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x1d17170,
>>>> [0x7f5303ffeca8], [0x7f5303ffecb0], [(nil)]) called
>>>> soa.c:616 soa_get_params() soa_get_params(static::0x1d17170, ...) called
>>>> nua_stack.c:271 nua_stack_event() nua(0x1d39800): event i_state 200 OK
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x1d12180): events IN
>>>> tport.c:2864 tport_recv_event() tport_recv_event(0x1d12180)
>>>> tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x1d12180) msg
>>>> 0x1d687a0 from (udp/22.22.22.22:5070) has 421 bytes, veclen = 1
>>>> recv 421 bytes from udp/[11.11.11.11]:5080 at 23:41:33.973154:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    ACK sip:2222222222 at 22.22.22.22:5070;transport=udp SIP/2.0
>>>>    Via: SIP/2.0/UDP 11.11.11.11:5080;rport;branch=z9hG4bKQ84rSgNcS9y3e
>>>>    Max-Forwards: 70
>>>>    From: "+111111111111" <sip:+111111111111 at 11.11.11.11
>>>> >;tag=H53g29BtQBSKj
>>>>    To: <sip:2222222222 at 22.22.22.22:5070>;tag=rZg31jSXgjK5r
>>>>    Call-ID: eeda303b-63bf-1232-feb0-f2eff32e29d0
>>>>    CSeq: 60453781 ACK
>>>>    Contact: <sip:mod_sofia at 11.11.11.11:5080>
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> tport.c:3023 tport_deliver() tport_deliver(0x1d12180): msg 0x1d687a0
>>>> (421 bytes) from udp/11.11.11.11:5070/sip next=(nil)
>>>> nta.c:2880 agent_recv_request() nta: received ACK
>>>> sip:2222222222 at 22.22.22.22:5070;transport=udp SIP/2.0 (CSeq 60453781)
>>>> nta.c:3019 agent_recv_request() nta: ACK (60453781) is going to INVITE
>>>> (60453781)
>>>> nua_session.c:2567 process_ack_or_cancel() nua: process_ack_or_cancel:
>>>> entering
>>>> soa.c:1214 soa_clear_remote_sdp()
>>>> soa_clear_remote_sdp(static::0x1d17170) called
>>>> nua_stack.c:271 nua_stack_event() nua(0x1d39800): event i_ack 200 OK
>>>> nua_session.c:4137 signal_call_state_change() nua(0x1d39800): call
>>>> state changed: completed -> ready
>>>> nua_stack.c:271 nua_stack_event() nua(0x1d39800): event i_state 200 OK
>>>> nua_stack.c:271 nua_stack_event() nua(0x1d39800): event i_active 200
>>>> Call active
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:798 nua_info() nua: nua_info: entering
>>>> nua_stack.c:529 nua_signal() nua(0x1d39800): sent signal r_info
>>>> nua_stack.c:569 nua_stack_signal() nua(0x1d39800): recv signal r_info
>>>> nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params:
>>>> entering
>>>> soa.c:403 soa_set_params() soa_set_params(static::0x1d17170, ...) called
>>>> nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
>>>> tport.c:3257 tport_tsend() tport_tsend(0x1d12180) tpn = */
>>>> 11.11.11.11:5080
>>>> tport.c:4046 tport_resolve() tport_resolve addrinfo = 11.11.11.11:5080
>>>> tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x1d12180): not
>>>> found by name */11.11.11.11:5080
>>>> tport.c:3594 tport_vsend() tport_vsend(0x1d12180): 658 bytes of 658 to
>>>> udp/11.11.11.11:5080
>>>> tport.c:3492 tport_send_msg() tport_vsend returned 658
>>>> send 658 bytes to udp/[11.11.11.11]:5080 at 23:41:34.010625:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    INFO sip:mod_sofia at 11.11.11.11:5080 SIP/2.0
>>>>    Via: SIP/2.0/UDP 22.22.22.22:5070;rport;branch=z9hG4bKDvBgeZXe0rvNg
>>>>    Max-Forwards: 70
>>>>    From: <sip:2222222222 at 22.22.22.22:5070>;tag=rZg31jSXgjK5r
>>>>    To: "+111111111111" <sip:+111111111111 at 11.11.11.11
>>>> >;tag=H53g29BtQBSKj
>>>>    Call-ID: eeda303b-63bf-1232-feb0-f2eff32e29d0
>>>>    CSeq: 60453783 INFO
>>>>    Contact: <sip:2222222222 at 22.22.22.22:5070;transport=udp>
>>>>    User-Agent: FS
>>>>    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>>>> NOTIFY
>>>>    Supported: timer, path, replaces
>>>>    Content-Type: message/update_display
>>>>    Content-Length: 0
>>>>    X-FS-Display-Name: Outbound Call
>>>>    X-FS-Display-Number: 002222222222
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> nta.c:8302 outgoing_send() nta: sent INFO (60453783) to */
>>>> 11.11.11.11:5080
>>>>  tport.c:4160 tport_pend() tport_pend(0x1d12180): pending 0x1d14e20 for
>>>> udp/22.22.22.22:5070 (already 0)
>>>> tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x1d12180): events IN
>>>> tport.c:2864 tport_recv_event() tport_recv_event(0x1d12180)
>>>> tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x1d12180) msg
>>>> 0x1d25520 from (udp/22.22.22.22:5070) has 460 bytes, veclen = 1
>>>> recv 460 bytes from udp/[11.11.11.11]:5080 at 23:41:34.012696:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    SIP/2.0 200 OK
>>>>    Via: SIP/2.0/UDP 22.22.22.22:5070
>>>> ;rport=5070;branch=z9hG4bKDvBgeZXe0rvNg
>>>>    From: <sip:2222222222 at 22.22.22.22:5070>;tag=rZg31jSXgjK5r
>>>>    To: "+111111111111" <sip:+111111111111 at 11.11.11.11
>>>> >;tag=H53g29BtQBSKj
>>>>    Call-ID: eeda303b-63bf-1232-feb0-f2eff32e29d0
>>>>    CSeq: 60453783 INFO
>>>>    User-Agent: FS
>>>>    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>>>> REGISTER, REFER, NOTIFY
>>>>    Supported: timer, path, replaces
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> tport.c:3023 tport_deliver() tport_deliver(0x1d12180): msg 0x1d25520
>>>> (460 bytes) from udp/11.11.11.11:5070/sip next=(nil)
>>>> nta.c:3297 agent_recv_response() nta: received 200 OK for INFO
>>>> (60453783)
>>>> nta.c:3364 agent_recv_response() nta: 200 OK is going to a transaction
>>>> nta.c:9562 outgoing_estimate_delay() nta_outgoing: RTT is 2.163 ms
>>>> tport.c:4222 tport_release() tport_release(0x1d12180): 0x1d14e20 by
>>>> 0x1cbd870 with 0x1d25520
>>>> nua_stack.c:271 nua_stack_event() nua(0x1d39800): event r_info 200 OK
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nta.c:1296 agent_timer() nta: timer set next to 4502 ms
>>>> nta.c:7132 _nta_incoming_timer() nta: timer I fired, terminate 200
>>>> response
>>>> nta.c:5823 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil),
>>>> 0x7f5303ffeb50)
>>>> nta.c:7186 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0
>>>> tout, 1/1 term, 1/1 free
>>>> nta.c:1296 agent_timer() nta: timer set next to 40 ms
>>>> nta.c:9099 outgoing_timer_dk() nta: timer K fired, terminate INFO
>>>> (60453783)
>>>> nta.c:8797 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil),
>>>> 0x7f5303ffecd0)
>>>> nta.c:8927 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0
>>>> tout, 1/1 term, 1/1 free
>>>> nta.c:1289 agent_timer() nta: timer not set
>>>> tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f5334004450):
>>>> events IN
>>>> tport.c:2864 tport_recv_event() tport_recv_event(0x7f5334004450)
>>>> tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f5334004450) msg
>>>> 0x7f533402ecc0 from (udp/22.22.22.22:5080) has 965 bytes, veclen = 1
>>>> recv 965 bytes from udp/[33.33.33.33]:5060 at 23:41:40.133750:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    INVITE sip:mod_sofia at 22.22.22.22:5080 SIP/2.0
>>>>    Max-Forwards: 29
>>>>    Session-Expires: 3600;refresher=uac
>>>>    Min-SE: 600
>>>>    Supported: timer, 100rel
>>>>    To: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    From: <sip:002222222222 at 33.33.33.33>;tag=3610568491-801417
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>    CSeq: 2 INVITE
>>>>     Allow: UPDATE,PRACK,INFO,OPTIONS,BYE,INVITE,ACK,CANCEL
>>>>    Via: SIP/2.0/UDP 33.33.33.33:5060
>>>> ;branch=z9hG4bKeff490529a8e1aac116cef0e2deb9648
>>>>    Contact: <sip:002222222222 at 33.33.33.33:5060>
>>>>    Content-Type: application/sdp
>>>>    Accept: application/sdp
>>>>    Content-Length: 353
>>>>
>>>>    v=0
>>>>    o=sbc-uk-bm-th02b 372172800 1401579694 IN IP4 33.33.33.33
>>>>    s=sip call
>>>>    c=IN IP4 33.33.33.34
>>>>    t=0 0
>>>>    m=image 43554 udptl t38
>>>>    a=sendrecv
>>>>    a=T38FaxVersion:0
>>>>    a=T38MaxBitRate:14400
>>>>    a=T38FaxRateManagement:transferredTCF
>>>>    a=T38FaxMaxBuffer:300
>>>>    a=T38FaxMaxDatagram:176
>>>>    a=T38FaxUdpEC:t38UDPRedundancy
>>>>    a=silenceSupp:off
>>>>    a=ptime:20
>>>>    a=maxptime:30
>>>>
>>>>  ------------------------------------------------------------------------
>>>> tport.c:3023 tport_deliver() tport_deliver(0x7f5334004450): msg
>>>> 0x7f533402ecc0 (965 bytes) from udp/33.33.33.33:5080/sip next=(nil)
>>>> nta.c:2880 agent_recv_request() nta: received INVITE
>>>> sip:mod_sofia at 22.22.22.22:5080 SIP/2.0 (CSeq 2)
>>>> nta.c:3246 agent_aliases() nta: canonizing
>>>> sip:mod_sofia at 22.22.22.22:5080 with contact
>>>> nta.c:3060 agent_recv_request() nta: INVITE (2) going to existing leg
>>>> nta.c:1348 set_timeout() nta: timer shortened to 200 ms
>>>> nua_server.c:102 nua_stack_process_request() nua:
>>>> nua_stack_process_request: entering
>>>> soa.c:1302 soa_init_offer_answer()
>>>> soa_init_offer_answer(static::0x7f533401eed0) called
>>>> soa.c:1171 soa_set_remote_sdp()
>>>> soa_set_remote_sdp(static::0x7f533401eed0, (nil), 0x7f533402f514, 353)
>>>> called
>>>> tport.c:3257 tport_tsend() tport_tsend(0x7f5334004450) tpn = UDP/
>>>> 33.33.33.33:5060
>>>> tport.c:4046 tport_resolve() tport_resolve addrinfo = 33.33.33.33:5060
>>>> tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f5334004450): not
>>>> found by name UDP/33.33.33.33:5060
>>>> tport.c:3594 tport_vsend() tport_vsend(0x7f5334004450): 344 bytes of
>>>> 344 to udp/33.33.33.33:5060
>>>> tport.c:3492 tport_send_msg() tport_vsend returned 344
>>>> send 344 bytes to udp/[33.33.33.33]:5060 at 23:41:40.134062:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    SIP/2.0 100 Trying
>>>>    Via: SIP/2.0/UDP 33.33.33.33:5060
>>>> ;branch=z9hG4bKeff490529a8e1aac116cef0e2deb9648
>>>>    From: <sip:002222222222 at 33.33.33.33>;tag=3610568491-801417
>>>>    To: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>    CSeq: 2 INVITE
>>>>    User-Agent: FS
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> nta.c:6789 incoming_reply() nta: sent 100 Trying for INVITE (2)
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event i_invite
>>>> 100 Trying
>>>> nua_session.c:4143 signal_call_state_change() nua(0x7f53700147d0):
>>>> ready call updated: received received offer
>>>> soa.c:1098 soa_get_remote_sdp()
>>>> soa_get_remote_sdp(static::0x7f533401eed0, [0x7f537d813598],
>>>> [0x7f537d8135a0], [(nil)]) called
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event i_state
>>>> 100 Trying
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nta.c:1296 agent_timer() nta: timer set next to 25631 ms
>>>> nta.c:9099 outgoing_timer_dk() nta: timer D fired, terminate INVITE
>>>> (60453781)
>>>> nta.c:8797 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil),
>>>> 0x7f537d813cd0)
>>>> nta.c:8927 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/1
>>>> tout, 1/1 term, 1/2 free
>>>> nta.c:1296 agent_timer() nta: timer set next to 1 ms
>>>> nta.c:8980 outgoing_timer_bf() nta: timer F fired, terminating ACK
>>>> (60453781)
>>>> nta.c:8797 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil),
>>>> 0x7f537d813cd0)
>>>> nta.c:8927 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 1/1
>>>> tout, 0/0 term, 1/1 free
>>>> nta.c:1289 agent_timer() nta: timer not set
>>>>
>>>> tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f5334004450):
>>>> events IN
>>>> tport.c:2864 tport_recv_event() tport_recv_event(0x7f5334004450)
>>>> tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f5334004450) msg
>>>> 0x7f5334029a40 from (udp/22.22.22.22:5080) has 512 bytes, veclen = 1
>>>> recv 512 bytes from udp/[33.33.33.33]:5060 at 23:44:22.741683:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    CANCEL sip:mod_sofia at 22.22.22.22:5080 SIP/2.0
>>>>    Max-Forwards: 69
>>>>    To: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    From: <sip:002222222222 at 33.33.33.33>;tag=3610568491-801417
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>    CSeq: 2 CANCEL
>>>>    Allow: UPDATE,INFO,OPTIONS,BYE,INVITE,ACK,CANCEL
>>>>    Via: SIP/2.0/UDP 33.33.33.33:5060
>>>> ;branch=z9hG4bKeff490529a8e1aac116cef0e2deb9648
>>>>    Contact: <sip:002222222222 at 33.33.33.33:5060>
>>>>    Reason: SIP;cause=403;text="Forbidden"
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> tport.c:3023 tport_deliver() tport_deliver(0x7f5334004450): msg
>>>> 0x7f5334029a40 (512 bytes) from udp/33.33.33.33:5080/sip next=(nil)
>>>> nta.c:2880 agent_recv_request() nta: received CANCEL
>>>> sip:mod_sofia at 22.22.22.22:5080 SIP/2.0 (CSeq 2)
>>>> nta.c:3026 agent_recv_request() nta: CANCEL (2) is going to INVITE (2)
>>>> tport.c:3257 tport_tsend() tport_tsend(0x7f5334004450) tpn = UDP/
>>>> 33.33.33.33:5060
>>>> tport.c:4046 tport_resolve() tport_resolve addrinfo = 33.33.33.33:5060
>>>> tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f5334004450): not
>>>> found by name UDP/33.33.33.33:5060
>>>> tport.c:3594 tport_vsend() tport_vsend(0x7f5334004450): 321 bytes of
>>>> 321 to udp/33.33.33.33:5060
>>>> tport.c:3492 tport_send_msg() tport_vsend returned 321
>>>> send 321 bytes to udp/[33.33.33.33]:5060 at 23:44:22.741804:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    SIP/2.0 200 OK
>>>>    Via: SIP/2.0/UDP 33.33.33.33:5060
>>>> ;branch=z9hG4bKeff490529a8e1aac116cef0e2deb9648
>>>>    From: <sip:002222222222 at 33.33.33.33>;tag=3610568491-801417
>>>>    To: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>    CSeq: 2 CANCEL
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> nua_session.c:2567 process_ack_or_cancel() nua: process_ack_or_cancel:
>>>> entering
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event i_cancel
>>>> 200 OK
>>>> nua_session.c:2318 nua_invite_server_respond() nua:
>>>> nua_invite_server_respond: entering
>>>> soa.c:1214 soa_clear_remote_sdp()
>>>> soa_clear_remote_sdp(static::0x7f533401eed0) called
>>>> tport.c:3257 tport_tsend() tport_tsend(0x7f5334004450) tpn = UDP/
>>>> 33.33.33.33:5060
>>>> tport.c:4046 tport_resolve() tport_resolve addrinfo = 33.33.33.33:5060
>>>> tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f5334004450): not
>>>> found by name UDP/33.33.33.33:5060
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> tport.c:3594 tport_vsend() tport_vsend(0x7f5334004450): 505 bytes of
>>>> 505 to udp/33.33.33.33:5060
>>>> tport.c:3492 tport_send_msg() tport_vsend returned 505
>>>> send 505 bytes to udp/[33.33.33.33]:5060 at 23:44:22.742006:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    SIP/2.0 487 Request Terminated
>>>>    Via: SIP/2.0/UDP 33.33.33.33:5060
>>>> ;branch=z9hG4bKeff490529a8e1aac116cef0e2deb9648
>>>>    From: <sip:002222222222 at 33.33.33.33>;tag=3610568491-801417
>>>>    To: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>    CSeq: 2 INVITE
>>>>    User-Agent: FS
>>>>    Accept: application/sdp
>>>>    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>>>> REGISTER, REFER, NOTIFY
>>>>    Supported: timer, path, replaces
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> nta.c:6789 incoming_reply() nta: sent 487 Request Terminated for INVITE
>>>> (2)
>>>> nta.c:1350 set_timeout() nta: timer set to 500 ms
>>>> nua_session.c:4143 signal_call_state_change() nua(0x7f53700147d0):
>>>> ready call updated: init
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event i_state
>>>> 487 Request Terminated
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event i_active
>>>> 487 Call active
>>>> soa.c:1302 soa_init_offer_answer()
>>>> soa_init_offer_answer(static::0x7f533401eed0) called
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f5334004450):
>>>> events IN
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> tport.c:2864 tport_recv_event() tport_recv_event(0x7f5334004450)
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f5334004450) msg
>>>> 0x7f533402d0b0 from (udp/22.22.22.22:5080) has 518 bytes, veclen = 1
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> recv 518 bytes from udp/[33.33.33.33]:5060 at 23:44:22.742365:
>>>>
>>>>  ------------------------------------------------------------------------
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>>    BYE sip:mod_sofia at 22.22.22.22:5080 SIP/2.0
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>>    Max-Forwards: 69
>>>>    To: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    From: <sip:002222222222 at 33.33.33.33>;tag=3610568491-801417
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>    CSeq: 3 BYE
>>>>    Allow: UPDATE,INFO,OPTIONS,BYE,INVITE,ACK,CANCEL
>>>>    Via: SIP/2.0/UDP 33.33.33.33:5060
>>>> ;branch=z9hG4bK6d90a278ed6e9b8f21c26aabb75e85e5
>>>>    Contact: <sip:002222222222 at 33.33.33.33:5060>
>>>>    Reason: Q.850;cause=16;text="Normal call clearing"
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> tport.c:3023 tport_deliver() tport_deliver(0x7f5334004450): msg
>>>> 0x7f533402d0b0 (518 bytes) from udp/33.33.33.33:5080/sip next=(nil)
>>>> nta.c:2880 agent_recv_request() nta: received BYE
>>>> sip:mod_sofia at 22.22.22.22:5080 SIP/2.0 (CSeq 3)
>>>> nta.c:3246 agent_aliases() nta: canonizing
>>>> sip:mod_sofia at 22.22.22.22:5080 with contact
>>>> nta.c:3060 agent_recv_request() nta: BYE (3) going to existing leg
>>>> nua_server.c:102 nua_stack_process_request() nua:
>>>> nua_stack_process_request: entering
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event i_bye 100
>>>> Trying
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:879 nua_respond() nua: nua_respond: entering
>>>> nua_stack.c:529 nua_signal() nua(0x7f53700147d0): sent signal r_respond
>>>> nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
>>>> nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
>>>> nua_stack.c:529 nua_signal() nua(0x7f53700147d0): sent signal r_destroy
>>>> nua_stack.c:573 nua_stack_signal() nua(0x7f53700147d0): recv signal
>>>> r_respond 200 OK
>>>> nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params:
>>>> entering
>>>> soa.c:403 soa_set_params() soa_set_params(static::0x7f533401eed0, ...)
>>>> called
>>>> tport.c:3257 tport_tsend() tport_tsend(0x7f5334004450) tpn = UDP/
>>>> 33.33.33.33:5060
>>>>  tport.c:4046 tport_resolve() tport_resolve addrinfo = 33.33.33.33:5060
>>>> tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f5334004450): not
>>>> found by name UDP/33.33.33.33:5060
>>>> tport.c:3594 tport_vsend() tport_vsend(0x7f5334004450): 461 bytes of
>>>> 461 to udp/33.33.33.33:5060
>>>> tport.c:3492 tport_send_msg() tport_vsend returned 461
>>>> send 461 bytes to udp/[33.33.33.33]:5060 at 23:44:22.744366:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    SIP/2.0 200 OK
>>>>    Via: SIP/2.0/UDP 33.33.33.33:5060
>>>> ;branch=z9hG4bK6d90a278ed6e9b8f21c26aabb75e85e5
>>>>    From: <sip:002222222222 at 33.33.33.33>;tag=3610568491-801417
>>>>    To: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>    CSeq: 3 BYE
>>>>    User-Agent: FS
>>>>    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>>>> REGISTER, REFER, NOTIFY
>>>>    Supported: timer, path, replaces
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> nta.c:6789 incoming_reply() nta: sent 200 OK for BYE (3)
>>>> nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f53700147d0):
>>>> removing session usage
>>>> nua_session.c:4137 signal_call_state_change() nua(0x7f53700147d0): call
>>>> state changed: ready -> terminated
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event i_state
>>>> 200 Session Terminated
>>>> nua_stack.c:271 nua_stack_event() nua(0x7f53700147d0): event
>>>> i_terminated 200 Session Terminated
>>>> soa.c:356 soa_destroy() soa_destroy(static::0x7f533401eed0) called
>>>> nta.c:4468 nta_leg_destroy() nta_leg_destroy(0x7f5334018320)
>>>> nua_stack.c:569 nua_stack_signal() nua(0x7f53700147d0): recv signal
>>>> r_destroy
>>>> nta.c:4468 nta_leg_destroy() nta_leg_destroy((nil))
>>>> nua.c:645 nua_bye() nua: nua_bye: entering
>>>> nua_stack.c:529 nua_signal() nua(0x1d39800): sent signal r_bye
>>>> nua_stack.c:569 nua_stack_signal() nua(0x1d39800): recv signal r_bye
>>>> nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params:
>>>> entering
>>>> soa.c:403 soa_set_params() soa_set_params(static::0x1d17170, ...) called
>>>> soa.c:1784 soa_terminate() soa_terminate(static::0x1d17170) called
>>>> soa.c:1302 soa_init_offer_answer()
>>>> soa_init_offer_answer(static::0x1d17170) called
>>>> nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
>>>> tport.c:3257 tport_tsend() tport_tsend(0x1d12180) tpn = */
>>>> 11.11.11.11:5080
>>>> tport.c:4046 tport_resolve() tport_resolve addrinfo = 11.11.11.11:5080
>>>> tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x1d12180): not
>>>> found by name */11.11.11.11:5080
>>>> tport.c:3594 tport_vsend() tport_vsend(0x1d12180): 599 bytes of 599 to
>>>> udp/11.11.11.11:5080
>>>> tport.c:3492 tport_send_msg() tport_vsend returned 599
>>>> send 599 bytes to udp/[11.11.11.11]:5080 at 23:44:22.751815:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    BYE sip:mod_sofia at 11.11.11.11:5080 SIP/2.0
>>>>    Via: SIP/2.0/UDP 22.22.22.22:5070;rport;branch=z9hG4bKe548FtejX1j8B
>>>>    Max-Forwards: 70
>>>>     From: <sip:2222222222 at 22.22.22.22:5070>;tag=rZg31jSXgjK5r
>>>>    To: "+111111111111" <sip:+111111111111 at 11.11.11.11
>>>> >;tag=H53g29BtQBSKj
>>>>    Call-ID: eeda303b-63bf-1232-feb0-f2eff32e29d0
>>>>    CSeq: 60453784 BYE
>>>>    Contact: <sip:2222222222 at 22.22.22.22:5070;transport=udp>
>>>>    User-Agent: FS
>>>>    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>>>> NOTIFY
>>>>    Supported: timer, path, replaces
>>>>    Reason: Q.850;cause=16;text="Normal call clearing"
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> nta.c:8302 outgoing_send() nta: sent BYE (60453784) to */
>>>> 11.11.11.11:5080
>>>> tport.c:4160 tport_pend() tport_pend(0x1d12180): pending 0x1d14e20 for
>>>> udp/22.22.22.22:5070 (already 0)
>>>> nta.c:1350 set_timeout() nta: timer set to 32000 ms
>>>> nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
>>>> tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x1d12180): events IN
>>>> tport.c:2864 tport_recv_event() tport_recv_event(0x1d12180)
>>>> tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x1d12180) msg
>>>> 0x1ca2550 from (udp/22.22.22.22:5070) has 459 bytes, veclen = 1
>>>> recv 459 bytes from udp/[11.11.11.11]:5080 at 23:44:22.755074:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    SIP/2.0 200 OK
>>>>    Via: SIP/2.0/UDP 22.22.22.22:5070
>>>> ;rport=5070;branch=z9hG4bKe548FtejX1j8B
>>>>    From: <sip:2222222222 at 22.22.22.22:5070>;tag=rZg31jSXgjK5r
>>>>    To: "+111111111111" <sip:+111111111111 at 11.11.11.11
>>>> >;tag=H53g29BtQBSKj
>>>>    Call-ID: eeda303b-63bf-1232-feb0-f2eff32e29d0
>>>>    CSeq: 60453784 BYE
>>>>    User-Agent: FS
>>>>    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
>>>> REGISTER, REFER, NOTIFY
>>>>    Supported: timer, path, replaces
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> tport.c:3023 tport_deliver() tport_deliver(0x1d12180): msg 0x1ca2550
>>>> (459 bytes) from udp/11.11.11.11:5070/sip next=(nil)
>>>> nta.c:3297 agent_recv_response() nta: received 200 OK for BYE (60453784)
>>>> nta.c:3364 agent_recv_response() nta: 200 OK is going to a transaction
>>>> nta.c:9562 outgoing_estimate_delay() nta_outgoing: RTT is 3.357 ms
>>>> tport.c:4222 tport_release() tport_release(0x1d12180): 0x1d14e20 by
>>>> 0x1d27170 with 0x1ca2550
>>>> nua_stack.c:271 nua_stack_event() nua(0x1d39800): event r_bye 200 OK
>>>> nua_session.c:4137 signal_call_state_change() nua(0x1d39800): call
>>>> state changed: terminating -> terminated
>>>> nua_stack.c:271 nua_stack_event() nua(0x1d39800): event i_state 200 to
>>>> BYE
>>>> nua_stack.c:359 nua_application_event() nua: nua_application_event:
>>>> entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
>>>> nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
>>>> nua_stack.c:569 nua_stack_signal() nua(0x1d39800): recv signal r_destroy
>>>> nta.c:4468 nta_leg_destroy() nta_leg_destroy((nil))
>>>> nua_stack.c:529 nua_signal() nua(0x1d39800): sent signal r_destroy
>>>> tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f5334004450):
>>>> events IN
>>>> tport.c:2864 tport_recv_event() tport_recv_event(0x7f5334004450)
>>>> tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f5334004450) msg
>>>> 0x7f5334032af0 from (udp/22.22.22.22:5080) has 466 bytes, veclen = 1
>>>> recv 466 bytes from udp/[33.33.33.33]:5060 at 23:44:22.759701:
>>>>
>>>>  ------------------------------------------------------------------------
>>>>    ACK sip:mod_sofia at 22.22.22.22:5080 SIP/2.0
>>>>    Max-Forwards: 70
>>>>    To: "+111111111111" <sip:+111111111111 at 22.22.22.22
>>>> >;tag=vg4Z33QvjBg5c
>>>>    From: <sip:002222222222 at 33.33.33.33>;tag=3610568491-801417
>>>>    Call-ID: eedb70c7-63bf-1232-47b6-02082072a337
>>>>    CSeq: 2 ACK
>>>>    Allow: UPDATE,INFO,OPTIONS,BYE,INVITE,ACK,CANCEL
>>>>    Via: SIP/2.0/UDP 33.33.33.33:5060
>>>> ;branch=z9hG4bKeff490529a8e1aac116cef0e2deb9648
>>>>    Contact: <sip:002222222222 at 33.33.33.33:5060>
>>>>    Content-Length: 0
>>>>
>>>>
>>>>  ------------------------------------------------------------------------
>>>> tport.c:3023 tport_deliver() tport_deliver(0x7f5334004450): msg
>>>> 0x7f5334032af0 (466 bytes) from udp/33.33.33.33:5080/sip next=(nil)
>>>> nta.c:2880 agent_recv_request() nta: received ACK
>>>> sip:mod_sofia at 22.22.22.22:5080 SIP/2.0 (CSeq 2)
>>>> nta.c:3019 agent_recv_request() nta: ACK (2) is going to INVITE (2)
>>>> nta.c:1296 agent_timer() nta: timer set next to 4517 ms
>>>> nta.c:1296 agent_timer() nta: timer set next to 4002 ms
>>>> nta.c:9099 outgoing_timer_dk() nta: timer K fired, terminate BYE
>>>> (60453784)
>>>> nta.c:8797 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil),
>>>> 0x7f5303ffecd0)
>>>> nta.c:8927 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0
>>>> tout, 1/1 term, 1/1 free
>>>> nta.c:1289 agent_timer() nta: timer not set
>>>> nta.c:7132 _nta_incoming_timer() nta: timer I fired, terminate 487
>>>> response
>>>> nta.c:5823 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil),
>>>> 0x7f537d813b50)
>>>> nta.c:7186 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0
>>>> tout, 1/2 term, 1/2 free
>>>> nta.c:1296 agent_timer() nta: timer set next to 26984 ms
>>>> nta.c:7157 _nta_incoming_timer() nta: timer J fired, terminate 200
>>>> response
>>>> nta.c:5823 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil),
>>>> 0x7f537d813b50)
>>>> nta.c:7186 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0
>>>> tout, 1/1 term, 1/1 free
>>>> nta.c:1289 agent_timer() nta: timer not set
>>>>
>>>>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> 
> 
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
>


-- 
Yours sincerely,
Vladimir Getmanshchuk
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140610/3f7c1917/attachment-0001.html 


Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users mailing list