<div dir="ltr">First, 1.0.6 is an absolutely ancient release now. Use the latest 1.2.12 release.<div><br></div><div>Second, you are using the logging of the internal Sofia SIP stack. That's very rarely needed... while useful sometimes in this case it's probably making the log overly verbose and harder to read as a result.</div>
<div><br></div><div>What looks a little odd is once the call is authenticated it doesn't appear to do anything for 10s until the hangup. Is this the complete log, or a selected excerpt? Normally the call would log itself looking through the dialplan showing what dialplan extensions matched and what actions would be/are being executed. I don't see that in the above.</div>
<div><br></div><div>Start by upgrading to 1.2 and then you'll get more assistance.</div></div><div class="gmail_extra"><br><br><div class="gmail_quote">On 1 September 2013 17:12, Guoren Chen <span dir="ltr"><<a href="mailto:guoren.chen@yahoo.com" target="_blank">guoren.chen@yahoo.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div><div style="font-size:12pt;font-family:times new roman,new york,times,serif"><div>Hi Experts,</div><div><br></div>
<div style="font-style:normal;font-size:16px;background-color:transparent;font-family:times new roman,new york,times,serif">I am new to this mailing list. </div><div style="font-style:normal;font-size:16px;background-color:transparent;font-family:times new roman,new york,times,serif">
<br></div><div style="font-style:normal;font-size:16px;background-color:transparent;font-family:times new roman,new york,times,serif">I
am trying to port the Freeswitch-1.0.6 to an embedded system. The
Freeswitch can run on the target and I can register two SIP sets on the
target. However, I can't make calls between them. I am using the default
configuration files copied from the Linux build. Here are the logs from
the target. Could some one help me to find out the issue? </div><div style="font-style:normal;font-size:16px;background-color:transparent;font-family:times new roman,new york,times,serif"><br></div><div style="font-style:normal;font-size:16px;background-color:transparent;font-family:times new roman,new york,times,serif">
The call was made from 1002 calling 1001. Freeswitch does not send req<span>uests to 1001. Then, 1002 sends CANCEL.</span></div><div style="font-style:normal;font-size:16px;background-color:transparent;font-family:times new roman,new york,times,serif">
<br><span></span></div><div style="font-style:normal;font-size:16px;background-color:transparent;font-family:times new roman,new york,times,serif"><span>Best Regards,</span></div><div style="font-style:normal;font-size:16px;background-color:transparent;font-family:times new roman,new york,times,serif">
<span>Guoren<br></span></div><div style="font-style:normal;font-size:16px;background-color:transparent;font-family:times new roman,new york,times,serif"><br></div><div style="font-style:normal;font-size:16px;background-color:transparent;font-family:times new roman,new york,times,serif">
tport_wakeup_pri(0x66fafcc0): events IN<br>tport_recv_event(0x66fafcc0)<br>tport_recv_iovec(0x66fafcc0) msg 0x670fd0c8 from (udp/<a href="http://192.168.1.101:5060" target="_blank">192.168.1.101:5060</a>) has 2 bytes, veclen = 1<br>
tport_deliver(0x66fafcc0): bad msg 0x670fd0c8 (2 bytes) from udp/<a href="http://192.168.1.127:5060/sip" target="_blank">192.168.1.127:5060/sip</a> next=0x0<br>nta_agent: received garbage from udp/<a href="http://192.168.1.127:5060/sip" target="_blank">192.168.1.127:5060/sip</a><br>
tport_wakeup_pri(0x66fafcc0): events IN<br>tport_recv_event(0x66fafcc0)<br>tport_recv_iovec(0x66fafcc0) msg 0x670fd0c8 from (udp/<a href="http://192.168.1.101:5060" target="_blank">192.168.1.101:5060</a>) has 2 bytes, veclen
= 1<br>tport_deliver(0x66fafcc0): bad msg 0x670fd0c8 (2 bytes) from udp/<a href="http://192.168.1.121:5060/sip" target="_blank">192.168.1.121:5060/sip</a> next=0x0<br>nta_agent: received garbage from udp/<a href="http://192.168.1.121:5060/sip" target="_blank">192.168.1.121:5060/sip</a><br>
tport_wakeup_pri(0x66fafcc0): events IN<br>tport_recv_event(0x66fafcc0)<br>tport_recv_iovec(0x66fafcc0) msg 0x670fd0c8 from (udp/<a href="http://192.168.1.101:5060" target="_blank">192.168.1.101:5060</a>) has 1023 bytes, veclen = 1<br>
recv 1023 bytes from udp/[192.168.1.127]:53708 at 14:33:17.958167:<br> ------------------------------------------------------------------------<br> INVITE <a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a> SIP/2.0<br>
Via: SIP/2.0/UDP 192.168.1.127:53708;rport;branch=z9hG4bKPjobYcaLv1k0J-Sc62VfANoNHr6WPEgFSH<br> Max-Forwards: 70<br> From: <<a href="mailto:sip%3A1002@192.168.1.101" target="_blank">sip:1002@192.168.1.101</a>>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx<br>
To: <<a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a>><br> Contact: <sip:1002@192.168.1.127:53708;ob><br> Call-ID:
QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK<br> CSeq: 23696 INVITE<br> Route: <sip:192.168.1.101;transport=udp;lr><br> Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS<br>
Supported: replaces, 100rel, timer, norefersub<br> Session-Expires: 1800<br> Min-SE: 90<br> User-Agent: CSipSimple_thunderg-8/r2272<br> Content-Type: application/sdp<br> Content-Length: 344<br> <br> v=0<br>
o=- 3587034797 3587034797 IN IP4 192.168.1.127<br> s=pjmedia<br> c=IN IP4 192.168.1.127<br> t=0 0<br> m=audio 4012 RTP/AVP 98 0 8 101<br> c=IN IP4 192.168.1.127<br> a=rtcp:4013 IN IP4 192.168.1.127<br> a=sendrecv<br>
a=rtpmap:98 SILK/16000<br> a=fmtp:98
useinbandfec=0<br> a=rtpmap:0 PCMU/8000<br> a=rtpmap:8 PCMA/8000<br> a=rtpmap:101 telephone-event/8000<br> a=fmtp:101 0-15<br> ------------------------------------------------------------------------<br>tport_deliver(0x66fafcc0): msg 0x670fd0c8 (1023 bytes) from udp/<a href="http://192.168.1.127:5060/sip" target="_blank">192.168.1.127:5060/sip</a> next=0x0<br>
nta: received INVITE <a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a> SIP/2.0 (CSeq 23696)<br>nta: canonizing <a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a> with contact<br>
nta: INVITE (23696) going to a default leg<br>nta: timer set to 200 ms<br>nua: nua_stack_process_request: entering<br>nua: nh_create: entering<br>nua: nh_create_handle: entering<br>nua: nua_stack_set_params: entering<br>
soa_clone(static::0x66f02188, 0x66eaa058, 0x67111080) called<br>
soa_set_params(static::0x6723ddf8, ...) called<br>nta_leg_tcreate(0x67111160)<br>soa_init_offer_answer(static::0x6723ddf8) called<br>soa_set_remote_sdp(static::0x6723ddf8, 0x0, 0x67111d97, 344)
called<br>nua(0x67111080): adding session usage<br>tport_tsend(0x66fafcc0) tpn = UDP/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>tport_resolve addrinfo = <a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>
tport_by_addrinfo(0x66fafcc0): not found by name UDP/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>tport_vsend(0x66fafcc0): 351 bytes of 351 to udp/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>
tport_vsend returned 351<br>send 351 bytes to udp/[192.168.1.127]:53708 at 14:33:17.976794:<br> ------------------------------------------------------------------------<br> SIP/2.0 100 Trying<br> Via: SIP/2.0/UDP 192.168.1.127:53708;rport=53708;branch=z9hG4bKPjobYcaLv1k0J-Sc62VfANoNHr6WPEgFSH<br>
From: <<a href="mailto:sip%3A1002@192.168.1.101" target="_blank">sip:1002@192.168.1.101</a>>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx<br> To: <<a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a>><br>
Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK<br> CSeq: 23696 INVITE<br> User-Agent: FreeSWITCH-mod_sofia/1.0.6-exported<br> Content-Length:
0<br> <br> ------------------------------------------------------------------------<br>nta: sent 100 Trying for INVITE (23696)<br>nua(0x67111080): event i_invite 100 Trying<br>nua(0x67111080): call state changed: init -> received, received offer<br>
soa_get_remote_sdp(static::0x6723ddf8, [0x68d1a8ec], [0x68d1a8f0], [0x0]) called<br>nua: nua_application_event: entering<br>nua(0x67111080): event i_state 100 Trying<br>2013-09-01 22:33:17.976039 [DEBUG] sofia.c:5856 IP 192.168.1.127 Rejected by acl "domains". Falling back to Digest auth.<br>
nua: nua_respond: entering<br>nua(0x67111080): sent signal r_respond<br>nua: nua_handle_magic: entering<br>nua: nua_handle_destroy: entering<br>nua(0x67111080): sent signal r_destroy<br>nua: nua_application_event: entering<br>
nua(0x67111080): event i_state dropped<br>nua(0x67111080): recv signal r_respond 407 Proxy Authentication Required<br>nua: nua_stack_set_params:
entering<br>soa_set_params(static::0x6723ddf8, ...) called<br>nua: nua_invite_server_respond: entering<br>soa_clear_remote_sdp(static::0x6723ddf8) called<br>tport_tsend(0x66fafcc0) tpn = UDP/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>
tport_resolve addrinfo = <a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>tport_by_addrinfo(0x66fafcc0): not found by name UDP/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>
tport_vsend(0x66fafcc0): 833 bytes of 833 to udp/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>tport_vsend returned 833<br>send 833 bytes to udp/[192.168.1.127]:53708 at 14:33:17.983158:<br>
------------------------------------------------------------------------<br> SIP/2.0 407 Proxy Authentication Required<br> Via: SIP/2.0/UDP 192.168.1.127:53708;rport=53708;branch=z9hG4bKPjobYcaLv1k0J-Sc62VfANoNHr6WPEgFSH<br>
From: <<a href="mailto:sip%3A1002@192.168.1.101" target="_blank">sip:1002@192.168.1.101</a>>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx<br> To: <<a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a>>;tag=9v5Hv8D1Z7emg<br>
Call-ID:
QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK<br> CSeq: 23696 INVITE<br> User-Agent: FreeSWITCH-mod_sofia/1.0.6-exported<br> Accept: application/sdp<br> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE<br>
Supported: timer, precondition, path, replaces<br>
Allow-Events: talk, presence, dialog, line-seize, call-info, sla,
include-session-description, presence.winfo, message-summary, refer<br> Proxy-Authenticate: Digest realm="192.168.1.101", nonce="7170d9ac-1313-11e3-b4ff-1f256118ae1c", algorithm=MD5, qop="auth"<br>
Content-Length: 0<br> <br> ------------------------------------------------------------------------<br>nta: sent 407 Proxy Authentication Required for INVITE (23696)<br>nua(0x67111080): removing session usage<br>nua(0x67111080): call state changed: received -> terminated<br>
nua(0x67111080): event i_state 407 Proxy Authentication Required<br>nua(0x67111080): event i_terminated 407 Proxy Authentication Required<br>soa_destroy(static::0x6723ddf8) called<br>nta_leg_destroy(0x67111160)<br>nua(0x67111080): recv signal r_destroy<br>
nta_leg_destroy(0x0)<br>tport_wakeup_pri(0x66fafcc0): events IN<br>tport_recv_event(0x66fafcc0)<br>tport_recv_iovec(0x66fafcc0) msg 0x67238bc8 from (udp/<a href="http://192.168.1.101:5060" target="_blank">192.168.1.101:5060</a>) has 391 bytes,
veclen = 1<br>recv 391 bytes from udp/[192.168.1.127]:53708 at 14:33:17.990814:<br> ------------------------------------------------------------------------<br> ACK <a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a> SIP/2.0<br>
Via: SIP/2.0/UDP 192.168.1.127:53708;rport;branch=z9hG4bKPjobYcaLv1k0J-Sc62VfANoNHr6WPEgFSH<br> Max-Forwards: 70<br> From: <<a href="mailto:sip%3A1002@192.168.1.101" target="_blank">sip:1002@192.168.1.101</a>>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx<br>
To: <<a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a>>;tag=9v5Hv8D1Z7emg<br> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK<br> CSeq: 23696 ACK<br> Route: <sip:192.168.1.101;transport=udp;lr><br>
Content-Length: 0<br> <br> ------------------------------------------------------------------------<br>tport_deliver(0x66fafcc0): msg 0x67238bc8 (391 bytes) from udp/<a href="http://192.168.1.127:5060/sip" target="_blank">192.168.1.127:5060/sip</a> next=0x0<br>
nta: received ACK <a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a>
SIP/2.0 (CSeq 23696)<br>nta: ACK (23696) is going to INVITE (23696)<br>tport_wakeup_pri(0x66fafcc0): events IN<br>tport_recv_event(0x66fafcc0)<br>tport_recv_iovec(0x66fafcc0) msg 0x67238bc8 from (udp/<a href="http://192.168.1.101:5060" target="_blank">192.168.1.101:5060</a>) has 1293 bytes, veclen = 1<br>
recv 1293 bytes from udp/[192.168.1.127]:53708 at 14:33:17.992057:<br> ------------------------------------------------------------------------<br> INVITE <a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a> SIP/2.0<br>
Via: SIP/2.0/UDP 192.168.1.127:53708;rport;branch=z9hG4bKPjaGeluUtZsgBXv.Qg12.KDnfSX20HvCLa<br> Max-Forwards: 70<br> From: <<a href="mailto:sip%3A1002@192.168.1.101" target="_blank">sip:1002@192.168.1.101</a>>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx<br>
To: <<a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a>><br> Contact: <sip:1002@192.168.1.127:53708;ob><br> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK<br> CSeq: 23697 INVITE<br>
Route:
<sip:192.168.1.101;transport=udp;lr><br> Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS<br> Supported: replaces, 100rel, timer, norefersub<br> Session-Expires: 1800<br>
Min-SE: 90<br> User-Agent: CSipSimple_thunderg-8/r2272<br>
Proxy-Authorization: Digest username="1002", realm="192.168.1.101",
nonce="7170d9ac-1313-11e3-b4ff-1f256118ae1c",
uri="<a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a>",
response="7030c512040326bd546d40934f2014c0", algorithm=MD5,
cnonce="8FFIKkeUBmBir9b4TvXVFFJPNm6uOzWJ", qop=auth, nc=00000001<br> Content-Type: application/sdp<br> Content-Length: 344<br> <br> v=0<br> o=- 3587034797 3587034797 IN IP4 192.168.1.127<br> s=pjmedia<br>
c=IN IP4 192.168.1.127<br> t=0 0<br> m=audio 4012 RTP/AVP 98 0 8 101<br> c=IN IP4 192.168.1.127<br> a=rtcp:4013 IN IP4 192.168.1.127<br> a=sendrecv<br> a=rtpmap:98 SILK/16000<br> a=fmtp:98 useinbandfec=0<br>
a=rtpmap:0 PCMU/8000<br> a=rtpmap:8 PCMA/8000<br> a=rtpmap:101 telephone-event/8000<br> a=fmtp:101 0-15<br> ------------------------------------------------------------------------<br>tport_deliver(0x66fafcc0): msg 0x67238bc8 (1293 bytes) from udp/<a href="http://192.168.1.127:5060/sip" target="_blank">192.168.1.127:5060/sip</a> next=0x0<br>
nta: received INVITE
<a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a> SIP/2.0 (CSeq 23697)<br>nta: canonizing <a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a> with contact<br>
nta: INVITE (23697) going to a default leg<br>nua: nua_stack_process_request: entering<br>nua: nh_create: entering<br>nua: nh_create_handle: entering<br>nua: nua_stack_set_params: entering<br>soa_clone(static::0x66f02188, 0x66eaa058, 0x67129d70) called<br>
soa_set_params(static::0x671122d8, ...) called<br>nta_leg_tcreate(0x670f2388)<br>soa_init_offer_answer(static::0x671122d8) called<br>soa_set_remote_sdp(static::0x671122d8, 0x0, 0x6723ddbd, 344) called<br>nua(0x67129d70): adding session usage<br>
tport_tsend(0x66fafcc0) tpn = UDP/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>tport_resolve addrinfo = <a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>tport_by_addrinfo(0x66fafcc0): not found by name UDP/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>
tport_vsend(0x66fafcc0): 351 bytes of 351 to udp/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>tport_vsend returned 351<br>send 351 bytes to udp/[192.168.1.127]:53708 at 14:33:17.993409:<br>
------------------------------------------------------------------------<br> SIP/2.0 100 Trying<br> Via: SIP/2.0/UDP 192.168.1.127:53708;rport=53708;branch=z9hG4bKPjaGeluUtZsgBXv.Qg12.KDnfSX20HvCLa<br> From: <<a href="mailto:sip%3A1002@192.168.1.101" target="_blank">sip:1002@192.168.1.101</a>>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx<br>
To: <<a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a>><br> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK<br> CSeq: 23697 INVITE<br> User-Agent: FreeSWITCH-mod_sofia/1.0.6-exported<br>
Content-Length: 0<br> <br> ------------------------------------------------------------------------<br>nta: sent 100 Trying for INVITE (23697)<br>nua(0x67129d70): event i_invite 100 Trying<br>nua: nua_application_event: entering<br>
2013-09-01 22:33:17.991895 [DEBUG] sofia.c:5856 IP 192.168.1.127 Rejected by acl "domains". Falling back to Digest auth.<br>nua(0x67129d70): call state changed: init ->
received, received offer<br>soa_get_remote_sdp(static::0x671122d8, [0x68d1a8ec], [0x68d1a8f0], [0x0]) called<br>nua(0x67129d70): event i_state 100 Trying<br>2013-09-01
22:33:17.999970 [NOTICE] switch_channel.c:669 New Channel
sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a> [71742bb6-1313-11e3-b500-1f256118ae1c]<br>nua: nua_handle_bind: entering<br>2013-09-01
22:33:18.000945 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>) Running State Change CS_NEW<br>2013-09-01 22:33:18.000945 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>) State NEW<br>
nua: nua_handle_magic: entering<br>nua: nua_application_event: entering<br>nta: timer set next to 4833 ms<br>nta: timer I fired, terminate 407 response<br>incoming_reclaim_all(0x0, 0x0, 0x68d1adc0)<br>nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/2 free<br>
nta: timer not set<br>tport_wakeup_pri(0x66fafcc0): events IN<br>tport_recv_event(0x66fafcc0)<br>tport_recv_iovec(0x66fafcc0) msg 0x670fd0c8 from (udp/<a href="http://192.168.1.101:5060" target="_blank">192.168.1.101:5060</a>) has 420 bytes, veclen = 1<br>
recv 420 bytes from udp/[192.168.1.127]:53708 at 14:33:29.147169:<br> ------------------------------------------------------------------------<br> CANCEL <a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a> SIP/2.0<br>
Via: SIP/2.0/UDP
192.168.1.127:53708;rport;branch=z9hG4bKPjaGeluUtZsgBXv.Qg12.KDnfSX20HvCLa<br> Max-Forwards: 70<br> From: <<a href="mailto:sip%3A1002@192.168.1.101" target="_blank">sip:1002@192.168.1.101</a>>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx<br>
To: <<a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a>><br> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK<br> CSeq: 23697 CANCEL<br> Route: <sip:192.168.1.101;transport=udp;lr><br>
User-Agent: CSipSimple_thunderg-8/r2272<br> Content-Length: 0<br> <br> ------------------------------------------------------------------------<br>tport_deliver(0x66fafcc0): msg 0x670fd0c8 (420 bytes) from udp/<a href="http://192.168.1.127:5060/sip" target="_blank">192.168.1.127:5060/sip</a> next=0x0<br>
nta: received CANCEL <a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a> SIP/2.0 (CSeq 23697)<br>nta: CANCEL (23697) is going to INVITE (23697)<br>tport_tsend(0x66fafcc0) tpn = UDP/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>
tport_resolve addrinfo = <a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>tport_by_addrinfo(0x66fafcc0):
not found by name UDP/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>tport_vsend(0x66fafcc0): 316 bytes of 316 to udp/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>
tport_vsend returned 316<br>send 316 bytes to udp/[192.168.1.127]:53708 at 14:33:29.149288:<br> ------------------------------------------------------------------------<br> SIP/2.0 200 OK<br> Via: SIP/2.0/UDP 192.168.1.127:53708;rport=53708;branch=z9hG4bKPjaGeluUtZsgBXv.Qg12.KDnfSX20HvCLa<br>
From: <<a href="mailto:sip%3A1002@192.168.1.101" target="_blank">sip:1002@192.168.1.101</a>>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx<br> To: <<a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a>>;tag=a6yay3y4vg56B<br>
Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK<br> CSeq: 23697 CANCEL<br> Content-Length: 0<br> <br> ------------------------------------------------------------------------<br>nua: process_ack_or_cancel: entering<br>
nua(0x67129d70): event i_cancel 200 OK<br>nua: nua_application_event: entering<br>nua:
nua_invite_server_respond: entering<br>soa_clear_remote_sdp(static::0x671122d8) called<br>tport_tsend(0x66fafcc0) tpn = UDP/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>tport_resolve addrinfo = <a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>
tport_by_addrinfo(0x66fafcc0): not found by name UDP/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>tport_vsend(0x66fafcc0): 699 bytes of 699 to udp/<a href="http://192.168.1.127:53708" target="_blank">192.168.1.127:53708</a><br>
tport_vsend returned 699<br>send 699 bytes to udp/[192.168.1.127]:53708 at 14:33:29.156960:<br> ------------------------------------------------------------------------<br> SIP/2.0 487 Request Terminated<br> Via: SIP/2.0/UDP 192.168.1.127:53708;rport=53708;branch=z9hG4bKPjaGeluUtZsgBXv.Qg12.KDnfSX20HvCLa<br>
From: <<a href="mailto:sip%3A1002@192.168.1.101" target="_blank">sip:1002@192.168.1.101</a>>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx<br> To: <<a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a>>;tag=a6yay3y4vg56B<br>
Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK<br> CSeq: 23697 INVITE<br> User-Agent:
FreeSWITCH-mod_sofia/1.0.6-exported<br> Accept: application/sdp<br> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE<br> Supported: timer, precondition, path, replaces<br>
Allow-Events: talk, presence, dialog, line-seize, call-info, sla,
include-session-description, presence.winfo, message-summary, refer<br> Content-Length: 0<br> <br> ------------------------------------------------------------------------<br>nta: sent 487 Request Terminated for INVITE (23697)<br>
nta: timer set to 500 ms<br>nua(0x67129d70): removing session usage<br>nua(0x67129d70): call state changed: received -> terminated<br>nua(0x67129d70): event i_state 487 Request Terminated<br>nua: nua_application_event: entering<br>
nua(0x67129d70): event i_terminated 487 Request Terminated<br>nua: nua_application_event: entering<br>soa_destroy(static::0x671122d8) called<br>nta_leg_destroy(0x670f2388)<br>tport_wakeup_pri(0x66fafcc0): events IN<br>tport_recv_event(0x66fafcc0)<br>
tport_recv_iovec(0x66fafcc0) msg 0x671275d0 from (udp/<a href="http://192.168.1.101:5060" target="_blank">192.168.1.101:5060</a>) has 391 bytes, veclen = 1<br>recv 391 bytes from udp/[192.168.1.127]:53708 at 14:33:29.172889:<br>
------------------------------------------------------------------------<br> ACK <a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a> SIP/2.0<br> Via: SIP/2.0/UDP 192.168.1.127:53708;rport;branch=z9hG4bKPjaGeluUtZsgBXv.Qg12.KDnfSX20HvCLa<br>
Max-Forwards: 70<br> From: <<a href="mailto:sip%3A1002@192.168.1.101" target="_blank">sip:1002@192.168.1.101</a>>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx<br> To: <<a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a>>;tag=a6yay3y4vg56B<br>
Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK<br> CSeq: 23697 ACK<br> Route: <sip:192.168.1.101;transport=udp;lr><br> Content-Length: 0<br> <br> ------------------------------------------------------------------------<br>
tport_deliver(0x66fafcc0): msg 0x671275d0 (391 bytes) from udp/<a href="http://192.168.1.127:5060/sip" target="_blank">192.168.1.127:5060/sip</a> next=0x0<br>nta: received ACK <a href="mailto:sip%3A1001@192.168.1.101" target="_blank">sip:1001@192.168.1.101</a> SIP/2.0 (CSeq 23697)<br>
nta: ACK (23697) is going to INVITE (23697)<br>nta: timer set next to 4526
ms<br>nta: timer I fired, terminate 487 response<br>incoming_reclaim_all(0x0, 0x0, 0x68d1adc0)<br>nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free<br>nta: timer not set<br>2013-09-01
22:34:20.044273 [CRIT] switch_core_state_machine.c:382
71742bb6-1313-11e3-b500-1f256118ae1c Timeout waiting for next
instruction in CS_NEW!<br>2013-09-01 22:34:20.044273 [NOTICE]
switch_core_state_machine.c:384 Hangup sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>
[CS_NEW] [INVALID_CALL_REFERENCE]<br>2013-09-01 22:34:20.044273 [DEBUG] switch_channel.c:2102 Send signal sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a> [KILL]<br>2013-09-01 22:34:20.044273 [DEBUG] switch_core_session.c:1021 Send signal sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a> [BREAK]<br>
2013-09-01
22:34:20.044273 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>) Running State Change CS_HANGUP<br>2013-09-01 22:34:20.044273 [DEBUG] switch_core_state_machine.c:499 (sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>) State HANGUP<br>
2013-09-01
22:34:20.044273 [DEBUG] mod_sofia.c:414 Channel
sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a> hanging up, cause:
INVALID_CALL_REFERENCE<br>2013-09-01 22:34:20.075383 [DEBUG] mod_sofia.c:476 Responding to INVITE with: 480<br>nua: nua_respond: entering<br>nua(0x67129d70): recv signal r_respond 480 Temporarily Unavailable<br>nua(0x67129d70): event i_error 500 Responding to a Non-Existing Request<br>
nua: nua_application_event: entering<br>nua(0x67129d70): sent signal r_respond<br>2013-09-01
22:34:20.076358 [DEBUG] switch_core_state_machine.c:46
sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a> Standard HANGUP, cause:
INVALID_CALL_REFERENCE<br>2013-09-01 22:34:20.076358 [DEBUG]
switch_core_state_machine.c:499 (sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>)
State HANGUP going to sleep<br>2013-09-01 22:34:20.078303 [DEBUG]
switch_core_state_machine.c:333 (sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>)
State Change CS_HANGUP -> CS_REPORTING<br>2013-09-01 22:34:20.078303 [DEBUG] switch_core_session.c:1021 Send signal sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a> [BREAK]<br>
2013-09-01
22:34:20.078303 [DEBUG] switch_core_state_machine.c:314
(sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>) Running State Change CS_REPORTING<br>2013-09-01 22:34:20.079283 [DEBUG] switch_core_state_machine.c:590 (sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>) State REPORTING<br>
2013-09-01
22:34:20.081246 [DEBUG] switch_core_state_machine.c:53
sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a> Standard REPORTING, cause:
INVALID_CALL_REFERENCE<br>2013-09-01 22:34:20.081246 [DEBUG]
switch_core_state_machine.c:590 (sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>)
State REPORTING going to sleep<br>2013-09-01 22:34:20.081246 [DEBUG]
switch_core_state_machine.c:327 (sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>)
State Change CS_REPORTING -> CS_DESTROY<br>2013-09-01 22:34:20.082232 [DEBUG] switch_core_session.c:1021 Send signal sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a> [BREAK]<br>
2013-09-01
22:34:20.082232 [DEBUG] switch_core_session.c:1164 Session 1
(sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>) Locked, Waiting on external entities<br>2013-09-01 22:34:20.082232 [NOTICE] switch_core_session.c:1182 Session 1 (sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>) Ended<br>
2013-09-01 22:34:20.082232 [NOTICE] switch_core_session.c:1184 Close Channel sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a> [CS_DESTROY]<br>2013-09-01
22:34:20.083207 [DEBUG] switch_core_state_machine.c:428
(sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>) Running State Change CS_DESTROY<br>2013-09-01 22:34:20.083207 [DEBUG] switch_core_state_machine.c:439 (sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>) State DESTROY<br>
2013-09-01 22:34:20.083207 [DEBUG] mod_sofia.c:341 sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a> SOFIA DESTROY<br>2013-09-01 22:34:20.083207 [DEBUG] switch_core_state_machine.c:60 sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a> Standard DESTROY<br>
2013-09-01
22:34:20.084324 [DEBUG] switch_core_state_machine.c:439
(sofia/internal/<a href="mailto:1002@192.168.1.101" target="_blank">1002@192.168.1.101</a>) State DESTROY going to sleep<br>tport_wakeup_pri(0x66fafcc0): events IN<br>tport_recv_event(0x66fafcc0)<br>tport_recv_iovec(0x66fafcc0) msg 0x6719d5e0 from (udp/<a href="http://192.168.1.101:5060" target="_blank">192.168.1.101:5060</a>) has 2 bytes, veclen = 1<br>
tport_deliver(0x66fafcc0): bad msg 0x6719d5e0 (2 bytes) from udp/<a href="http://192.168.1.127:5060/sip" target="_blank">192.168.1.127:5060/sip</a> next=0x0<br>nta_agent: received garbage from udp/<a href="http://192.168.1.127:5060/sip" target="_blank">192.168.1.127:5060/sip</a><br>
tport_wakeup_pri(0x66fafcc0): events IN<br>tport_recv_event(0x66fafcc0)<br>tport_recv_iovec(0x66fafcc0) msg 0x6719d5e0 from (udp/<a href="http://192.168.1.101:5060" target="_blank">192.168.1.101:5060</a>) has 2 bytes, veclen = 1<br>
tport_deliver(0x66fafcc0): bad msg 0x6719d5e0 (2 bytes) from udp/<a href="http://192.168.1.121:5060/sip" target="_blank">192.168.1.121:5060/sip</a> next=0x0<br>nta_agent: received garbage from udp/<a href="http://192.168.1.121:5060/sip" target="_blank">192.168.1.121:5060/sip</a><br>
tport_wakeup_pri(0x66fafcc0): events IN<br>tport_recv_event(0x66fafcc0)<br>tport_recv_iovec(0x66fafcc0) msg 0x6719d5e0 from (udp/<a href="http://192.168.1.101:5060" target="_blank">192.168.1.101:5060</a>) has 2 bytes, veclen = 1<br>
tport_deliver(0x66fafcc0): bad msg 0x6719d5e0
(2 bytes) from udp/<a href="http://192.168.1.127:5060/sip" target="_blank">192.168.1.127:5060/sip</a> next=0x0<br>nta_agent: received garbage from udp/<a href="http://192.168.1.127:5060/sip" target="_blank">192.168.1.127:5060/sip</a><br>
tport_wakeup_pri(0x66fafcc0): events IN<br>tport_recv_event(0x66fafcc0)<br>tport_recv_iovec(0x66fafcc0) msg 0x6719d5e0 from (udp/<a href="http://192.168.1.101:5060" target="_blank">192.168.1.101:5060</a>) has 2 bytes, veclen = 1<br>
tport_deliver(0x66fafcc0): bad msg 0x6719d5e0 (2 bytes) from udp/<a href="http://192.168.1.121:5060/sip" target="_blank">192.168.1.121:5060/sip</a> next=0x0<br>nta_agent: received garbage from udp/<a href="http://192.168.1.121:5060/sip" target="_blank">192.168.1.121:5060/sip</a><br>
tport_wakeup_pri(0x66fafcc0): events IN<br>tport_recv_event(0x66fafcc0)<br>tport_recv_iovec(0x66fafcc0) msg 0x6719d5e0 from (udp/<a href="http://192.168.1.101:5060" target="_blank">192.168.1.101:5060</a>) has 2 bytes, veclen = 1<br>
tport_deliver(0x66fafcc0): bad msg 0x6719d5e0 (2 bytes) from udp/<a href="http://192.168.1.127:5060/sip" target="_blank">192.168.1.127:5060/sip</a> next=0x0<br></div></div></div><br>_________________________________________________________________________<br>
Professional FreeSWITCH Consulting Services:<br>
<a href="mailto:consulting@freeswitch.org">consulting@freeswitch.org</a><br>
<a href="http://www.freeswitchsolutions.com" target="_blank">http://www.freeswitchsolutions.com</a><br>
<br>
FreeSWITCH-powered IP PBX: The CudaTel Communication Server<br>
<a href="http://www.cudatel.com" target="_blank">http://www.cudatel.com</a><br>
<br>
Official FreeSWITCH Sites<br>
<a href="http://www.freeswitch.org" target="_blank">http://www.freeswitch.org</a><br>
<a href="http://wiki.freeswitch.org" target="_blank">http://wiki.freeswitch.org</a><br>
<a href="http://www.cluecon.com" target="_blank">http://www.cluecon.com</a><br>
<br>
FreeSWITCH-dev mailing list<br>
<a href="mailto:FreeSWITCH-dev@lists.freeswitch.org">FreeSWITCH-dev@lists.freeswitch.org</a><br>
<a href="http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev" target="_blank">http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev</a><br>
UNSUBSCRIBE:<a href="http://lists.freeswitch.org/mailman/options/freeswitch-dev" target="_blank">http://lists.freeswitch.org/mailman/options/freeswitch-dev</a><br>
<a href="http://www.freeswitch.org" target="_blank">http://www.freeswitch.org</a><br>
<br></blockquote></div><br></div>