[Freeswitch-dev] Registered two SIP sets, but can't make calls
Anthony Minessale
anthony.minessale at gmail.com
Tue Sep 3 23:26:22 MSD 2013
It looks like whatever changed the state from new to init was not triggered
by the 2nd invite.
You could try disabling auth-calls and turn off the acls.
The area in question in the mod_sofia code has been completely redone since
this version so there is no use in debugging it.
There are more modern builds of FS for openwrt to play with.
On Mon, Sep 2, 2013 at 7:44 PM, Guoren Chen <guoren.chen at yahoo.com> wrote:
> Hi Steven and Stanislav,
>
> Thanks for your responses. The reason I have choosen 1.0.6 was because I
> could refer the DD-WRT embedded porting and it has fewer modules. I just
> want to prove it works on my target, then I can work on the newer FS
> releases.
>
> The log I posted is just sections from the call was made to the call
> hangup. What logs do you need to identify the issue? How do I check if the
> dialplan was executed or not? Or how do I check what events are send to
> dialplan. There's no ERR messages of the call failure.
>
> I build the same load on Ubuntu and it works fine. Is there a way to check
> if the database works okay?
>
> Best Regards,
> Guoren
>
> ------------------------------
> *From:* Steven Ayre <steveayre at gmail.com>
> *To:* "freeswitch-dev at lists.freeswitch.org" <
> freeswitch-dev at lists.freeswitch.org>
> *Sent:* Monday, September 2, 2013 10:43 AM
>
> *Subject:* Re: [Freeswitch-dev] Registered two SIP sets, but can't make
> calls
>
> True.
>
> But 1) it's age makes it harder to support because of the number of
> changes made since then and 2) there are many known bugs which have been
> fixed since then. It's entirely possible that there have been changes since
> then that might affect embedded platforms which might not appear on desktop
> architectures.
>
> If he's working on packaging FreeSWITCH for an embedded system his time
> would be far better spent using the latest stable version rather than
> having to later repeat all his work when upgrading to that version.
>
> Ignoring version, his log still lacks any of the dialplan processing to
> see what's happening to the call. We're still waiting to know if that was
> the entire call log or just an excerpt.
>
>
>
>
>
> On 1 September 2013 22:25, Stanislav Sinyagin <ssinyagin at yahoo.com> wrote:
>
> but honestly, 1.0.6 is a completely functional release, and a simple call
> like this should work the same :)
>
>
>
> ------------------------------
> *From:* Steven Ayre <steveayre at gmail.com>
> *To:* "freeswitch-dev at lists.freeswitch.org" <
> freeswitch-dev at lists.freeswitch.org>
> *Sent:* Sunday, September 1, 2013 10:17 PM
> *Subject:* Re: [Freeswitch-dev] Registered two SIP sets, but can't make
> calls
>
> First, 1.0.6 is an absolutely ancient release now. Use the latest 1.2.12
> release.
>
> 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.
>
> 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.
>
> Start by upgrading to 1.2 and then you'll get more assistance.
>
>
> On 1 September 2013 17:12, Guoren Chen <guoren.chen at yahoo.com> wrote:
>
> Hi Experts,
>
> I am new to this mailing list.
>
> 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?
>
> The call was made from 1002 calling 1001. Freeswitch does not send requests
> to 1001. Then, 1002 sends CANCEL.
>
> Best Regards,
> Guoren
>
> tport_wakeup_pri(0x66fafcc0): events IN
> tport_recv_event(0x66fafcc0)
> tport_recv_iovec(0x66fafcc0) msg 0x670fd0c8 from (udp/192.168.1.101:5060)
> has 2 bytes, veclen = 1
> tport_deliver(0x66fafcc0): bad msg 0x670fd0c8 (2 bytes) from udp/
> 192.168.1.127:5060/sip next=0x0
> nta_agent: received garbage from udp/192.168.1.127:5060/sip
> tport_wakeup_pri(0x66fafcc0): events IN
> tport_recv_event(0x66fafcc0)
> tport_recv_iovec(0x66fafcc0) msg 0x670fd0c8 from (udp/192.168.1.101:5060)
> has 2 bytes, veclen = 1
> tport_deliver(0x66fafcc0): bad msg 0x670fd0c8 (2 bytes) from udp/
> 192.168.1.121:5060/sip next=0x0
> nta_agent: received garbage from udp/192.168.1.121:5060/sip
> tport_wakeup_pri(0x66fafcc0): events IN
> tport_recv_event(0x66fafcc0)
> tport_recv_iovec(0x66fafcc0) msg 0x670fd0c8 from (udp/192.168.1.101:5060)
> has 1023 bytes, veclen = 1
> recv 1023 bytes from udp/[192.168.1.127]:53708 at 14:33:17.958167:
> ------------------------------------------------------------------------
> INVITE sip:1001 at 192.168.1.101 SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.127:53708
> ;rport;branch=z9hG4bKPjobYcaLv1k0J-Sc62VfANoNHr6WPEgFSH
> Max-Forwards: 70
> From: <sip:1002 at 192.168.1.101>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx
> To: <sip:1001 at 192.168.1.101>
> Contact: <sip:1002 at 192.168.1.127:53708;ob>
> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK
> CSeq: 23696 INVITE
> Route: <sip:192.168.1.101;transport=udp;lr>
> Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE,
> NOTIFY, REFER, MESSAGE, OPTIONS
> Supported: replaces, 100rel, timer, norefersub
> Session-Expires: 1800
> Min-SE: 90
> User-Agent: CSipSimple_thunderg-8/r2272
> Content-Type: application/sdp
> Content-Length: 344
>
> v=0
> o=- 3587034797 3587034797 IN IP4 192.168.1.127
> s=pjmedia
> c=IN IP4 192.168.1.127
> t=0 0
> m=audio 4012 RTP/AVP 98 0 8 101
> c=IN IP4 192.168.1.127
> a=rtcp:4013 IN IP4 192.168.1.127
> a=sendrecv
> a=rtpmap:98 SILK/16000
> a=fmtp:98 useinbandfec=0
> a=rtpmap:0 PCMU/8000
> a=rtpmap:8 PCMA/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-15
> ------------------------------------------------------------------------
> tport_deliver(0x66fafcc0): msg 0x670fd0c8 (1023 bytes) from udp/
> 192.168.1.127:5060/sip next=0x0
> nta: received INVITE sip:1001 at 192.168.1.101 SIP/2.0 (CSeq 23696)
> nta: canonizing sip:1001 at 192.168.1.101 with contact
> nta: INVITE (23696) going to a default leg
> nta: timer set to 200 ms
> nua: nua_stack_process_request: entering
> nua: nh_create: entering
> nua: nh_create_handle: entering
> nua: nua_stack_set_params: entering
> soa_clone(static::0x66f02188, 0x66eaa058, 0x67111080) called
> soa_set_params(static::0x6723ddf8, ...) called
> nta_leg_tcreate(0x67111160)
> soa_init_offer_answer(static::0x6723ddf8) called
> soa_set_remote_sdp(static::0x6723ddf8, 0x0, 0x67111d97, 344) called
> nua(0x67111080): adding session usage
> tport_tsend(0x66fafcc0) tpn = UDP/192.168.1.127:53708
> tport_resolve addrinfo = 192.168.1.127:53708
> tport_by_addrinfo(0x66fafcc0): not found by name UDP/192.168.1.127:53708
> tport_vsend(0x66fafcc0): 351 bytes of 351 to udp/192.168.1.127:53708
> tport_vsend returned 351
> send 351 bytes to udp/[192.168.1.127]:53708 at 14:33:17.976794:
> ------------------------------------------------------------------------
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP 192.168.1.127:53708
> ;rport=53708;branch=z9hG4bKPjobYcaLv1k0J-Sc62VfANoNHr6WPEgFSH
> From: <sip:1002 at 192.168.1.101>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx
> To: <sip:1001 at 192.168.1.101>
> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK
> CSeq: 23696 INVITE
> User-Agent: FreeSWITCH-mod_sofia/1.0.6-exported
> Content-Length: 0
>
> ------------------------------------------------------------------------
> nta: sent 100 Trying for INVITE (23696)
> nua(0x67111080): event i_invite 100 Trying
> nua(0x67111080): call state changed: init -> received, received offer
> soa_get_remote_sdp(static::0x6723ddf8, [0x68d1a8ec], [0x68d1a8f0], [0x0])
> called
> nua: nua_application_event: entering
> nua(0x67111080): event i_state 100 Trying
> 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.
> nua: nua_respond: entering
> nua(0x67111080): sent signal r_respond
> nua: nua_handle_magic: entering
> nua: nua_handle_destroy: entering
> nua(0x67111080): sent signal r_destroy
> nua: nua_application_event: entering
> nua(0x67111080): event i_state dropped
> nua(0x67111080): recv signal r_respond 407 Proxy Authentication Required
> nua: nua_stack_set_params: entering
> soa_set_params(static::0x6723ddf8, ...) called
> nua: nua_invite_server_respond: entering
> soa_clear_remote_sdp(static::0x6723ddf8) called
> tport_tsend(0x66fafcc0) tpn = UDP/192.168.1.127:53708
> tport_resolve addrinfo = 192.168.1.127:53708
> tport_by_addrinfo(0x66fafcc0): not found by name UDP/192.168.1.127:53708
> tport_vsend(0x66fafcc0): 833 bytes of 833 to udp/192.168.1.127:53708
> tport_vsend returned 833
> send 833 bytes to udp/[192.168.1.127]:53708 at 14:33:17.983158:
> ------------------------------------------------------------------------
> SIP/2.0 407 Proxy Authentication Required
> Via: SIP/2.0/UDP 192.168.1.127:53708
> ;rport=53708;branch=z9hG4bKPjobYcaLv1k0J-Sc62VfANoNHr6WPEgFSH
> From: <sip:1002 at 192.168.1.101>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx
> To: <sip:1001 at 192.168.1.101>;tag=9v5Hv8D1Z7emg
> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK
> CSeq: 23696 INVITE
> User-Agent: FreeSWITCH-mod_sofia/1.0.6-exported
> Accept: application/sdp
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
> REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
> Supported: timer, precondition, path, replaces
> Allow-Events: talk, presence, dialog, line-seize, call-info, sla,
> include-session-description, presence.winfo, message-summary, refer
> Proxy-Authenticate: Digest realm="192.168.1.101",
> nonce="7170d9ac-1313-11e3-b4ff-1f256118ae1c", algorithm=MD5, qop="auth"
> Content-Length: 0
>
> ------------------------------------------------------------------------
> nta: sent 407 Proxy Authentication Required for INVITE (23696)
> nua(0x67111080): removing session usage
> nua(0x67111080): call state changed: received -> terminated
> nua(0x67111080): event i_state 407 Proxy Authentication Required
> nua(0x67111080): event i_terminated 407 Proxy Authentication Required
> soa_destroy(static::0x6723ddf8) called
> nta_leg_destroy(0x67111160)
> nua(0x67111080): recv signal r_destroy
> nta_leg_destroy(0x0)
> tport_wakeup_pri(0x66fafcc0): events IN
> tport_recv_event(0x66fafcc0)
> tport_recv_iovec(0x66fafcc0) msg 0x67238bc8 from (udp/192.168.1.101:5060)
> has 391 bytes, veclen = 1
> recv 391 bytes from udp/[192.168.1.127]:53708 at 14:33:17.990814:
> ------------------------------------------------------------------------
> ACK sip:1001 at 192.168.1.101 SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.127:53708
> ;rport;branch=z9hG4bKPjobYcaLv1k0J-Sc62VfANoNHr6WPEgFSH
> Max-Forwards: 70
> From: <sip:1002 at 192.168.1.101>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx
> To: <sip:1001 at 192.168.1.101>;tag=9v5Hv8D1Z7emg
> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK
> CSeq: 23696 ACK
> Route: <sip:192.168.1.101;transport=udp;lr>
> Content-Length: 0
>
> ------------------------------------------------------------------------
> tport_deliver(0x66fafcc0): msg 0x67238bc8 (391 bytes) from udp/
> 192.168.1.127:5060/sip next=0x0
> nta: received ACK sip:1001 at 192.168.1.101 SIP/2.0 (CSeq 23696)
> nta: ACK (23696) is going to INVITE (23696)
> tport_wakeup_pri(0x66fafcc0): events IN
> tport_recv_event(0x66fafcc0)
> tport_recv_iovec(0x66fafcc0) msg 0x67238bc8 from (udp/192.168.1.101:5060)
> has 1293 bytes, veclen = 1
> recv 1293 bytes from udp/[192.168.1.127]:53708 at 14:33:17.992057:
> ------------------------------------------------------------------------
> INVITE sip:1001 at 192.168.1.101 SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.127:53708
> ;rport;branch=z9hG4bKPjaGeluUtZsgBXv.Qg12.KDnfSX20HvCLa
> Max-Forwards: 70
> From: <sip:1002 at 192.168.1.101>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx
> To: <sip:1001 at 192.168.1.101>
> Contact: <sip:1002 at 192.168.1.127:53708;ob>
> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK
> CSeq: 23697 INVITE
> Route: <sip:192.168.1.101;transport=udp;lr>
> Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE,
> NOTIFY, REFER, MESSAGE, OPTIONS
> Supported: replaces, 100rel, timer, norefersub
> Session-Expires: 1800
> Min-SE: 90
> User-Agent: CSipSimple_thunderg-8/r2272
> Proxy-Authorization: Digest username="1002", realm="192.168.1.101",
> nonce="7170d9ac-1313-11e3-b4ff-1f256118ae1c", uri="sip:1001 at 192.168.1.101",
> response="7030c512040326bd546d40934f2014c0", algorithm=MD5,
> cnonce="8FFIKkeUBmBir9b4TvXVFFJPNm6uOzWJ", qop=auth, nc=00000001
> Content-Type: application/sdp
> Content-Length: 344
>
> v=0
> o=- 3587034797 3587034797 IN IP4 192.168.1.127
> s=pjmedia
> c=IN IP4 192.168.1.127
> t=0 0
> m=audio 4012 RTP/AVP 98 0 8 101
> c=IN IP4 192.168.1.127
> a=rtcp:4013 IN IP4 192.168.1.127
> a=sendrecv
> a=rtpmap:98 SILK/16000
> a=fmtp:98 useinbandfec=0
> a=rtpmap:0 PCMU/8000
> a=rtpmap:8 PCMA/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-15
> ------------------------------------------------------------------------
> tport_deliver(0x66fafcc0): msg 0x67238bc8 (1293 bytes) from udp/
> 192.168.1.127:5060/sip next=0x0
> nta: received INVITE sip:1001 at 192.168.1.101 SIP/2.0 (CSeq 23697)
> nta: canonizing sip:1001 at 192.168.1.101 with contact
> nta: INVITE (23697) going to a default leg
> nua: nua_stack_process_request: entering
> nua: nh_create: entering
> nua: nh_create_handle: entering
> nua: nua_stack_set_params: entering
> soa_clone(static::0x66f02188, 0x66eaa058, 0x67129d70) called
> soa_set_params(static::0x671122d8, ...) called
> nta_leg_tcreate(0x670f2388)
> soa_init_offer_answer(static::0x671122d8) called
> soa_set_remote_sdp(static::0x671122d8, 0x0, 0x6723ddbd, 344) called
> nua(0x67129d70): adding session usage
> tport_tsend(0x66fafcc0) tpn = UDP/192.168.1.127:53708
> tport_resolve addrinfo = 192.168.1.127:53708
> tport_by_addrinfo(0x66fafcc0): not found by name UDP/192.168.1.127:53708
> tport_vsend(0x66fafcc0): 351 bytes of 351 to udp/192.168.1.127:53708
> tport_vsend returned 351
> send 351 bytes to udp/[192.168.1.127]:53708 at 14:33:17.993409:
> ------------------------------------------------------------------------
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP 192.168.1.127:53708
> ;rport=53708;branch=z9hG4bKPjaGeluUtZsgBXv.Qg12.KDnfSX20HvCLa
> From: <sip:1002 at 192.168.1.101>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx
> To: <sip:1001 at 192.168.1.101>
> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK
> CSeq: 23697 INVITE
> User-Agent: FreeSWITCH-mod_sofia/1.0.6-exported
> Content-Length: 0
>
> ------------------------------------------------------------------------
> nta: sent 100 Trying for INVITE (23697)
> nua(0x67129d70): event i_invite 100 Trying
> nua: nua_application_event: entering
> 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.
> nua(0x67129d70): call state changed: init -> received, received offer
> soa_get_remote_sdp(static::0x671122d8, [0x68d1a8ec], [0x68d1a8f0], [0x0])
> called
> nua(0x67129d70): event i_state 100 Trying
> 2013-09-01 22:33:17.999970 [NOTICE] switch_channel.c:669 New Channel
> sofia/internal/1002 at 192.168.1.101 [71742bb6-1313-11e3-b500-1f256118ae1c]
> nua: nua_handle_bind: entering
> 2013-09-01 22:33:18.000945 [DEBUG] switch_core_state_machine.c:314
> (sofia/internal/1002 at 192.168.1.101) Running State Change CS_NEW
> 2013-09-01 22:33:18.000945 [DEBUG] switch_core_state_machine.c:320
> (sofia/internal/1002 at 192.168.1.101) State NEW
> nua: nua_handle_magic: entering
> nua: nua_application_event: entering
> nta: timer set next to 4833 ms
> nta: timer I fired, terminate 407 response
> incoming_reclaim_all(0x0, 0x0, 0x68d1adc0)
> nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/2 free
> nta: timer not set
> tport_wakeup_pri(0x66fafcc0): events IN
> tport_recv_event(0x66fafcc0)
> tport_recv_iovec(0x66fafcc0) msg 0x670fd0c8 from (udp/192.168.1.101:5060)
> has 420 bytes, veclen = 1
> recv 420 bytes from udp/[192.168.1.127]:53708 at 14:33:29.147169:
> ------------------------------------------------------------------------
> CANCEL sip:1001 at 192.168.1.101 SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.127:53708
> ;rport;branch=z9hG4bKPjaGeluUtZsgBXv.Qg12.KDnfSX20HvCLa
> Max-Forwards: 70
> From: <sip:1002 at 192.168.1.101>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx
> To: <sip:1001 at 192.168.1.101>
> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK
> CSeq: 23697 CANCEL
> Route: <sip:192.168.1.101;transport=udp;lr>
> User-Agent: CSipSimple_thunderg-8/r2272
> Content-Length: 0
>
> ------------------------------------------------------------------------
> tport_deliver(0x66fafcc0): msg 0x670fd0c8 (420 bytes) from udp/
> 192.168.1.127:5060/sip next=0x0
> nta: received CANCEL sip:1001 at 192.168.1.101 SIP/2.0 (CSeq 23697)
> nta: CANCEL (23697) is going to INVITE (23697)
> tport_tsend(0x66fafcc0) tpn = UDP/192.168.1.127:53708
> tport_resolve addrinfo = 192.168.1.127:53708
> tport_by_addrinfo(0x66fafcc0): not found by name UDP/192.168.1.127:53708
> tport_vsend(0x66fafcc0): 316 bytes of 316 to udp/192.168.1.127:53708
> tport_vsend returned 316
> send 316 bytes to udp/[192.168.1.127]:53708 at 14:33:29.149288:
> ------------------------------------------------------------------------
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 192.168.1.127:53708
> ;rport=53708;branch=z9hG4bKPjaGeluUtZsgBXv.Qg12.KDnfSX20HvCLa
> From: <sip:1002 at 192.168.1.101>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx
> To: <sip:1001 at 192.168.1.101>;tag=a6yay3y4vg56B
> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK
> CSeq: 23697 CANCEL
> Content-Length: 0
>
> ------------------------------------------------------------------------
> nua: process_ack_or_cancel: entering
> nua(0x67129d70): event i_cancel 200 OK
> nua: nua_application_event: entering
> nua: nua_invite_server_respond: entering
> soa_clear_remote_sdp(static::0x671122d8) called
> tport_tsend(0x66fafcc0) tpn = UDP/192.168.1.127:53708
> tport_resolve addrinfo = 192.168.1.127:53708
> tport_by_addrinfo(0x66fafcc0): not found by name UDP/192.168.1.127:53708
> tport_vsend(0x66fafcc0): 699 bytes of 699 to udp/192.168.1.127:53708
> tport_vsend returned 699
> send 699 bytes to udp/[192.168.1.127]:53708 at 14:33:29.156960:
> ------------------------------------------------------------------------
> SIP/2.0 487 Request Terminated
> Via: SIP/2.0/UDP 192.168.1.127:53708
> ;rport=53708;branch=z9hG4bKPjaGeluUtZsgBXv.Qg12.KDnfSX20HvCLa
> From: <sip:1002 at 192.168.1.101>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx
> To: <sip:1001 at 192.168.1.101>;tag=a6yay3y4vg56B
> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK
> CSeq: 23697 INVITE
> User-Agent: FreeSWITCH-mod_sofia/1.0.6-exported
> Accept: application/sdp
> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO,
> REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
> Supported: timer, precondition, path, replaces
> Allow-Events: talk, presence, dialog, line-seize, call-info, sla,
> include-session-description, presence.winfo, message-summary, refer
> Content-Length: 0
>
> ------------------------------------------------------------------------
> nta: sent 487 Request Terminated for INVITE (23697)
> nta: timer set to 500 ms
> nua(0x67129d70): removing session usage
> nua(0x67129d70): call state changed: received -> terminated
> nua(0x67129d70): event i_state 487 Request Terminated
> nua: nua_application_event: entering
> nua(0x67129d70): event i_terminated 487 Request Terminated
> nua: nua_application_event: entering
> soa_destroy(static::0x671122d8) called
> nta_leg_destroy(0x670f2388)
> tport_wakeup_pri(0x66fafcc0): events IN
> tport_recv_event(0x66fafcc0)
> tport_recv_iovec(0x66fafcc0) msg 0x671275d0 from (udp/192.168.1.101:5060)
> has 391 bytes, veclen = 1
> recv 391 bytes from udp/[192.168.1.127]:53708 at 14:33:29.172889:
> ------------------------------------------------------------------------
> ACK sip:1001 at 192.168.1.101 SIP/2.0
> Via: SIP/2.0/UDP 192.168.1.127:53708
> ;rport;branch=z9hG4bKPjaGeluUtZsgBXv.Qg12.KDnfSX20HvCLa
> Max-Forwards: 70
> From: <sip:1002 at 192.168.1.101>;tag=kixbEsV8lfAeqJQCxjCz.pQROBdSABlx
> To: <sip:1001 at 192.168.1.101>;tag=a6yay3y4vg56B
> Call-ID: QMiyKhBszEBh1szWNPnrCKG1j5CJsXGK
> CSeq: 23697 ACK
> Route: <sip:192.168.1.101;transport=udp;lr>
> Content-Length: 0
>
> ------------------------------------------------------------------------
> tport_deliver(0x66fafcc0): msg 0x671275d0 (391 bytes) from udp/
> 192.168.1.127:5060/sip next=0x0
> nta: received ACK sip:1001 at 192.168.1.101 SIP/2.0 (CSeq 23697)
> nta: ACK (23697) is going to INVITE (23697)
> nta: timer set next to 4526 ms
> nta: timer I fired, terminate 487 response
> incoming_reclaim_all(0x0, 0x0, 0x68d1adc0)
> nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
> nta: timer not set
> 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!
> 2013-09-01 22:34:20.044273 [NOTICE] switch_core_state_machine.c:384 Hangup
> sofia/internal/1002 at 192.168.1.101 [CS_NEW] [INVALID_CALL_REFERENCE]
> 2013-09-01 22:34:20.044273 [DEBUG] switch_channel.c:2102 Send signal
> sofia/internal/1002 at 192.168.1.101 [KILL]
> 2013-09-01 22:34:20.044273 [DEBUG] switch_core_session.c:1021 Send signal
> sofia/internal/1002 at 192.168.1.101 [BREAK]
> 2013-09-01 22:34:20.044273 [DEBUG] switch_core_state_machine.c:314
> (sofia/internal/1002 at 192.168.1.101) Running State Change CS_HANGUP
> 2013-09-01 22:34:20.044273 [DEBUG] switch_core_state_machine.c:499
> (sofia/internal/1002 at 192.168.1.101) State HANGUP
> 2013-09-01 22:34:20.044273 [DEBUG] mod_sofia.c:414 Channel sofia/internal/
> 1002 at 192.168.1.101 hanging up, cause: INVALID_CALL_REFERENCE
> 2013-09-01 22:34:20.075383 [DEBUG] mod_sofia.c:476 Responding to INVITE
> with: 480
> nua: nua_respond: entering
> nua(0x67129d70): recv signal r_respond 480 Temporarily Unavailable
> nua(0x67129d70): event i_error 500 Responding to a Non-Existing Request
> nua: nua_application_event: entering
> nua(0x67129d70): sent signal r_respond
> 2013-09-01 22:34:20.076358 [DEBUG] switch_core_state_machine.c:46
> sofia/internal/1002 at 192.168.1.101 Standard HANGUP, cause:
> INVALID_CALL_REFERENCE
> 2013-09-01 22:34:20.076358 [DEBUG] switch_core_state_machine.c:499
> (sofia/internal/1002 at 192.168.1.101) State HANGUP going to sleep
> 2013-09-01 22:34:20.078303 [DEBUG] switch_core_state_machine.c:333
> (sofia/internal/1002 at 192.168.1.101) State Change CS_HANGUP -> CS_REPORTING
> 2013-09-01 22:34:20.078303 [DEBUG] switch_core_session.c:1021 Send signal
> sofia/internal/1002 at 192.168.1.101 [BREAK]
> 2013-09-01 22:34:20.078303 [DEBUG] switch_core_state_machine.c:314
> (sofia/internal/1002 at 192.168.1.101) Running State Change CS_REPORTING
> 2013-09-01 22:34:20.079283 [DEBUG] switch_core_state_machine.c:590
> (sofia/internal/1002 at 192.168.1.101) State REPORTING
> 2013-09-01 22:34:20.081246 [DEBUG] switch_core_state_machine.c:53
> sofia/internal/1002 at 192.168.1.101 Standard REPORTING, cause:
> INVALID_CALL_REFERENCE
> 2013-09-01 22:34:20.081246 [DEBUG] switch_core_state_machine.c:590
> (sofia/internal/1002 at 192.168.1.101) State REPORTING going to sleep
> 2013-09-01 22:34:20.081246 [DEBUG] switch_core_state_machine.c:327
> (sofia/internal/1002 at 192.168.1.101) State Change CS_REPORTING ->
> CS_DESTROY
> 2013-09-01 22:34:20.082232 [DEBUG] switch_core_session.c:1021 Send signal
> sofia/internal/1002 at 192.168.1.101 [BREAK]
> 2013-09-01 22:34:20.082232 [DEBUG] switch_core_session.c:1164 Session 1
> (sofia/internal/1002 at 192.168.1.101) Locked, Waiting on external entities
> 2013-09-01 22:34:20.082232 [NOTICE] switch_core_session.c:1182 Session 1
> (sofia/internal/1002 at 192.168.1.101) Ended
> 2013-09-01 22:34:20.082232 [NOTICE] switch_core_session.c:1184 Close
> Channel sofia/internal/1002 at 192.168.1.101 [CS_DESTROY]
> 2013-09-01 22:34:20.083207 [DEBUG] switch_core_state_machine.c:428
> (sofia/internal/1002 at 192.168.1.101) Running State Change CS_DESTROY
> 2013-09-01 22:34:20.083207 [DEBUG] switch_core_state_machine.c:439
> (sofia/internal/1002 at 192.168.1.101) State DESTROY
> 2013-09-01 22:34:20.083207 [DEBUG] mod_sofia.c:341 sofia/internal/
> 1002 at 192.168.1.101 SOFIA DESTROY
> 2013-09-01 22:34:20.083207 [DEBUG] switch_core_state_machine.c:60
> sofia/internal/1002 at 192.168.1.101 Standard DESTROY
> 2013-09-01 22:34:20.084324 [DEBUG] switch_core_state_machine.c:439
> (sofia/internal/1002 at 192.168.1.101) State DESTROY going to sleep
> tport_wakeup_pri(0x66fafcc0): events IN
> tport_recv_event(0x66fafcc0)
> tport_recv_iovec(0x66fafcc0) msg 0x6719d5e0 from (udp/192.168.1.101:5060)
> has 2 bytes, veclen = 1
> tport_deliver(0x66fafcc0): bad msg 0x6719d5e0 (2 bytes) from udp/
> 192.168.1.127:5060/sip next=0x0
> nta_agent: received garbage from udp/192.168.1.127:5060/sip
> tport_wakeup_pri(0x66fafcc0): events IN
> tport_recv_event(0x66fafcc0)
> tport_recv_iovec(0x66fafcc0) msg 0x6719d5e0 from (udp/192.168.1.101:5060)
> has 2 bytes, veclen = 1
> tport_deliver(0x66fafcc0): bad msg 0x6719d5e0 (2 bytes) from udp/
> 192.168.1.121:5060/sip next=0x0
> nta_agent: received garbage from udp/192.168.1.121:5060/sip
> tport_wakeup_pri(0x66fafcc0): events IN
> tport_recv_event(0x66fafcc0)
> tport_recv_iovec(0x66fafcc0) msg 0x6719d5e0 from (udp/192.168.1.101:5060)
> has 2 bytes, veclen = 1
> tport_deliver(0x66fafcc0): bad msg 0x6719d5e0 (2 bytes) from udp/
> 192.168.1.127:5060/sip next=0x0
> nta_agent: received garbage from udp/192.168.1.127:5060/sip
> tport_wakeup_pri(0x66fafcc0): events IN
> tport_recv_event(0x66fafcc0)
> tport_recv_iovec(0x66fafcc0) msg 0x6719d5e0 from (udp/192.168.1.101:5060)
> has 2 bytes, veclen = 1
> tport_deliver(0x66fafcc0): bad msg 0x6719d5e0 (2 bytes) from udp/
> 192.168.1.121:5060/sip next=0x0
> nta_agent: received garbage from udp/192.168.1.121:5060/sip
> tport_wakeup_pri(0x66fafcc0): events IN
> tport_recv_event(0x66fafcc0)
> tport_recv_iovec(0x66fafcc0) msg 0x6719d5e0 from (udp/192.168.1.101:5060)
> has 2 bytes, veclen = 1
> tport_deliver(0x66fafcc0): bad msg 0x6719d5e0 (2 bytes) from udp/
> 192.168.1.127:5060/sip next=0x0
>
> _________________________________________________________________________
> 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-dev mailing list
> FreeSWITCH-dev at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev
> http://www.freeswitch.org
>
>
>
> _________________________________________________________________________
> 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-dev mailing list
> FreeSWITCH-dev at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev
> http://www.freeswitch.org
>
>
>
> _________________________________________________________________________
> 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-dev mailing list
> FreeSWITCH-dev at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev
> http://www.freeswitch.org
>
>
>
> _________________________________________________________________________
> 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-dev mailing list
> FreeSWITCH-dev at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev
> http://www.freeswitch.org
>
>
>
> _________________________________________________________________________
> 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-dev mailing list
> FreeSWITCH-dev at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-dev
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-dev
> http://www.freeswitch.org
>
>
--
Anthony Minessale II
FreeSWITCH http://www.freeswitch.org/
ClueCon http://www.cluecon.com/
Twitter: http://twitter.com/FreeSWITCH_wire
AIM: anthm
MSN:anthony_minessale at hotmail.com
GTALK/JABBER/PAYPAL:anthony.minessale at gmail.com
IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference
sip:888 at conference.freeswitch.org
googletalk:conf+888 at conference.freeswitch.org
pstn:+19193869900
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-dev/attachments/20130903/4e8bbc0e/attachment-0001.html
Join us at ClueCon 2013 Aug 6-8, 2013
More information about the FreeSWITCH-dev
mailing list