[Home]

Summary:ASTERISK-17427: SIP over TCP and TLS does not appear to support NAT=yes
Reporter:Cabel McCoy (cabel mccoy)Labels:
Date Opened:2011-02-17 16:55:39.000-0600Date Closed:2011-02-18 11:20:26.000-0600
Priority:BlockerRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/TCP-TLS
Versions:1.8.2 Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:I am using a soft client to test SIP over TCP and I am having problems getting RTP to send traffic back to my NATed ip address. Nat works perfectly with UDP but not with TCP or TCP/TLS.

Here is the output from my RTP Debug

TCP connection gives me this
Sent RTP packet to      192.168.49.16:10004 (type 09, seq 043932, ts 108160, len 000170)

Which never gets back to me because its my private IP.

UDP connection gives me this
Sent RTP packet to      99.137.230.28:10000 (type 09, seq 015177, ts 000320, len 000170)

Works great.
Comments:By: Cabel McCoy (cabel mccoy) 2011-02-17 18:20:48.000-0600

====== TCP NOT WORKING CORRECTLY WITH NAT =====
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: = Looking for  Call ID: acGNeYt.ru9qIu.v-MSJU76g3iXSUd7Q (Checking From) --From tag NEVOcM-IdhnmPUFM7rmIRRa0fIAxc6hy --To-tag  
[Feb 17 16:12:46] DEBUG[20578] acl.c: For destination '99.137.230.28', our source address is '10.10.0.53'.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Target address 99.137.230.28:59795 is not local, substituting externaddr
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Setting SIP_TRANSPORT_TCP with address 70.88.55.9:5060
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Allocating new SIP dialog for acGNeYt.ru9qIu.v-MSJU76g3iXSUd7Q - INVITE (No RTP)
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Feb 17 16:12:46] DEBUG[20578] sip/reqresp_parser.c: Begin: parsing SIP "Supported: 100rel"
[Feb 17 16:12:46] DEBUG[20578] sip/reqresp_parser.c: Found SIP option: -100rel-
[Feb 17 16:12:46] DEBUG[20578] sip/reqresp_parser.c: Matched SIP option: 100rel
[Feb 17 16:12:46] DEBUG[20578] netsock2.c: Splitting '192.168.49.16:59795' gives...
[Feb 17 16:12:46] DEBUG[20578] netsock2.c: ...host '192.168.49.16' and port '59795'.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Trying to put 'SIP/2.0 401' onto TCP socket destined for 99.137.230.28:59795
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: = Looking for  Call ID: acGNeYt.ru9qIu.v-MSJU76g3iXSUd7Q (Checking From) --From tag NEVOcM-IdhnmPUFM7rmIRRa0fIAxc6hy --To-tag as7a4204a9  
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Stopping retransmission on 'acGNeYt.ru9qIu.v-MSJU76g3iXSUd7Q' of Response 31645: Match Not Found
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: = Looking for  Call ID: acGNeYt.ru9qIu.v-MSJU76g3iXSUd7Q (Checking From) --From tag NEVOcM-IdhnmPUFM7rmIRRa0fIAxc6hy --To-tag  
[Feb 17 16:12:46] DEBUG[20578] netsock2.c: Splitting 'pub.angushamer.com' gives...
[Feb 17 16:12:46] DEBUG[20578] netsock2.c: ...host 'pub.angushamer.com' and port '(null)'.
[Feb 17 16:12:46] DEBUG[20578] netsock2.c: Splitting 'pub.angushamer.com' gives...
[Feb 17 16:12:46] DEBUG[20578] netsock2.c: ...host 'pub.angushamer.com' and port '(null)'.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Feb 17 16:12:46] DEBUG[20578] netsock2.c: Splitting '192.168.49.16:59795' gives...
[Feb 17 16:12:46] DEBUG[20578] netsock2.c: ...host '192.168.49.16' and port '59795'.
[Feb 17 16:12:46] DEBUG[20578] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xcd77640'
[Feb 17 16:12:46] DEBUG[20578] res_rtp_asterisk.c: Allocated port 10218 for RTP instance '0xcd77640'
[Feb 17 16:12:46] DEBUG[20578] rtp_engine.c: RTP instance '0xcd77640' is setup and ready to go
[Feb 17 16:12:46] DEBUG[20578] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xcd77640'
[Feb 17 16:12:46] VERBOSE[20578] netsock2.c:   == Using SIP RTP CoS mark 5
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Setting NAT on RTP to On
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing session-level SDP o=- 3506976766 3506976766 IN IP4 192.168.49.16... UNSUPPORTED.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing session-level SDP s=Blink 0.23.2 (MacOSX)... UNSUPPORTED.
[Feb 17 16:12:46] DEBUG[20578] netsock2.c: Splitting '192.168.49.16' gives...
[Feb 17 16:12:46] DEBUG[20578] netsock2.c: ...host '192.168.49.16' and port '(null)'.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.49.16... OK.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED.
[Feb 17 16:12:46] DEBUG[20578] rtp_engine.c: Setting payload 9 based on m type on 0x76b0ad0
[Feb 17 16:12:46] DEBUG[20578] rtp_engine.c: Setting payload 104 based on m type on 0x76b0ad0
[Feb 17 16:12:46] DEBUG[20578] rtp_engine.c: Setting payload 103 based on m type on 0x76b0ad0
[Feb 17 16:12:46] DEBUG[20578] rtp_engine.c: Setting payload 102 based on m type on 0x76b0ad0
[Feb 17 16:12:46] DEBUG[20578] rtp_engine.c: Setting payload 0 based on m type on 0x76b0ad0
[Feb 17 16:12:46] DEBUG[20578] rtp_engine.c: Setting payload 8 based on m type on 0x76b0ad0
[Feb 17 16:12:46] DEBUG[20578] rtp_engine.c: Setting payload 117 based on m type on 0x76b0ad0
[Feb 17 16:12:46] DEBUG[20578] rtp_engine.c: Setting payload 3 based on m type on 0x76b0ad0
[Feb 17 16:12:46] DEBUG[20578] rtp_engine.c: Setting payload 101 based on m type on 0x76b0ad0
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=rtcp:10009... UNSUPPORTED.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:104 speex/32000... OK.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:103 speex/16000... OK.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:102 speex/8000... OK.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:117 iLBC/8000... OK.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=fmtp:117 mode=20... UNSUPPORTED.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED.
[Feb 17 16:12:46] DEBUG[20578] sip/sdp_crypto.c: local_key64 ejD0uaYLQsudgLOEYRnafDZ4TNiplmJBX3Btc06Y len 40
[Feb 17 16:12:46] DEBUG[20578] sip/sdp_crypto.c: SRTP policy activated
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:+1JMCWieIDWu4YKhBXjei4y8iBVDVsr52RfC1NkU... OK.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: We've already processed a crypto attribute, skipping 'crypto:2 AES_CM_128_HMAC_SHA1_32 inline:Eb0fV8OeG61VfLLsDrlCo8oqTx716T2Ddm+apyzI'
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:Eb0fV8OeG61VfLLsDrlCo8oqTx716T2Ddm+apyzI... UNSUPPORTED.
[Feb 17 16:12:46] DEBUG[20578] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK.


===== UDP IS WORKING CORRECTLY WITH NAT =======
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: = Looking for  Call ID: LyAruuyvkUezIASTZrvqIv9i1nOYkIfW (Checking From) --From tag vz.Fcoxxb8JnC7tj5Z3Ws7WPMFOKO2.T --To-tag  
[Feb 17 16:15:47] DEBUG[20544] acl.c: For destination '99.137.230.28', our source address is '10.10.0.53'.
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: Target address 99.137.230.28:55616 is not local, substituting externaddr
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 70.88.55.9:5060
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: Allocating new SIP dialog for LyAruuyvkUezIASTZrvqIv9i1nOYkIfW - INVITE (No RTP)
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Feb 17 16:15:47] DEBUG[20544] sip/reqresp_parser.c: Begin: parsing SIP "Supported: 100rel"
[Feb 17 16:15:47] DEBUG[20544] sip/reqresp_parser.c: Found SIP option: -100rel-
[Feb 17 16:15:47] DEBUG[20544] sip/reqresp_parser.c: Matched SIP option: 100rel
[Feb 17 16:15:47] DEBUG[20544] netsock2.c: Splitting '99.137.230.28:51974' gives...
[Feb 17 16:15:47] DEBUG[20544] netsock2.c: ...host '99.137.230.28' and port '51974'.
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 99.137.230.28:55616
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: = Looking for  Call ID: LyAruuyvkUezIASTZrvqIv9i1nOYkIfW (Checking From) --From tag vz.Fcoxxb8JnC7tj5Z3Ws7WPMFOKO2.T --To-tag as2ff7782b  
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: Stopping retransmission on 'LyAruuyvkUezIASTZrvqIv9i1nOYkIfW' of Response 18964: Match Found
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: = Looking for  Call ID: LyAruuyvkUezIASTZrvqIv9i1nOYkIfW (Checking From) --From tag vz.Fcoxxb8JnC7tj5Z3Ws7WPMFOKO2.T --To-tag  
[Feb 17 16:15:47] DEBUG[20544] netsock2.c: Splitting 'pub.angushamer.com' gives...
[Feb 17 16:15:47] DEBUG[20544] netsock2.c: ...host 'pub.angushamer.com' and port '(null)'.
[Feb 17 16:15:47] DEBUG[20544] netsock2.c: Splitting 'pub.angushamer.com' gives...
[Feb 17 16:15:47] DEBUG[20544] netsock2.c: ...host 'pub.angushamer.com' and port '(null)'.
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[Feb 17 16:15:47] DEBUG[20544] netsock2.c: Splitting '99.137.230.28:51974' gives...
[Feb 17 16:15:47] DEBUG[20544] netsock2.c: ...host '99.137.230.28' and port '51974'.
[Feb 17 16:15:47] DEBUG[20544] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xcd770c0'
[Feb 17 16:15:47] DEBUG[20544] res_rtp_asterisk.c: Allocated port 18948 for RTP instance '0xcd770c0'
[Feb 17 16:15:47] DEBUG[20544] rtp_engine.c: RTP instance '0xcd770c0' is setup and ready to go
[Feb 17 16:15:47] DEBUG[20544] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xcd770c0'
[Feb 17 16:15:47] VERBOSE[20544] netsock2.c:   == Using SIP RTP CoS mark 5
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: Setting NAT on RTP to On
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED.
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: Processing session-level SDP o=- 3506976947 3506976947 IN IP4 99.137.230.28... UNSUPPORTED.
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: Processing session-level SDP s=Blink 0.23.2 (MacOSX)... UNSUPPORTED.
[Feb 17 16:15:47] DEBUG[20544] netsock2.c: Splitting '99.137.230.28' gives...
[Feb 17 16:15:47] DEBUG[20544] netsock2.c: ...host '99.137.230.28' and port '(null)'.
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: Processing session-level SDP c=IN IP4 99.137.230.28... OK.
[Feb 17 16:15:47] DEBUG[20544] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED.
By: Walter Doekes (wdoekes) 2011-02-18 02:29:42.000-0600

I could be wrong, but it looks like the SDP in the UDP case is already "fixed"/rewritten by an ALG/SBC/router.

I would expect to see the same 192-address in the UDP case, and the RTP stream to be correctly matched first after traffic *from* your LAN arrives on the asterisk.

Does any packet *from* your LAN ever arrive in the TLS case? (rtp set debug on)

What happens with the UDP case if you disable SIP/SDP rewriting in your router?
By: Walter Doekes (wdoekes) 2011-02-18 02:35:56.000-0600

BTW, is your asterisk *also* behind NAT?
By: Cabel McCoy (cabel mccoy) 2011-02-18 09:51:57.000-0600

Yes both phone and asterisk are behind NAT at different locations. I tried to disable the ALG in my router and it appears the SDP is getting re-written somewhere else, probably in my DSL router, which I have no control over. Do you know if it would be possible to re-write the SDP with the SIP_TRANSPORT_TCP address if NAT is set to yes? I think this would solve my issue with double nat and TLS/TCP connections.
So what your saying is that in the UDP case the RTP stream waits for packets from my client and if they arrive then it uses that source address? If so how would this work for TCP since its not stateless? I will start a packet capture on my client and on the asterisk box to see what happens to the RTP packets on UDP and TCP.

Thanks for your help!
By: Cabel McCoy (cabel mccoy) 2011-02-18 10:05:47.000-0600

I found my problem,
I needed to open the RTP ports on the router in front of asterisk. Looks like the ALG was doing this for me on UDP but it cannot see into the SIP/TLS packets to do it. When I manually opened these ports my problem went away. Thanks for pointing me in the right direction with RTP.
By: Elazar Broad (ebroad) 2011-02-18 11:20:25.000-0600

Network configuration issue.