[Serusers] Deadly embrace with rtpproxy - Is it necessary? Can it be turned off?
Frank Durda IV
frank.durda at hypercube-llc.com
Fri Dec 5 01:13:17 CET 2008
Andres wrote:
> I see this in your output:
>
>> :callee's address filled in: 10.31.168.2:16004 (RTP)
>
> Which means it received audio from that IP.
>
> What I don't see is rtpproxy "prefilling" the addresses (caller and
> callee) with the SDP data which is used to send audio until we know what
> the real ip/port is. You should be seeing some info like:
>
> pre-filling caller's address with....
> pre-filling callee's address with....
>
> If you don't see that, then are you sure that data is coming in the SDP
> Invite? Without that info, rtpproxy has no way to relay your rtp before
> receiving rtp from the other end.
Yes, there is a functional SDP payload in the INVITE, the 183 Session
Progress,
and the 200 OK messages. That's why I have been unable to figure out
why rtpproxy didn't have enough information to go on from the INVITE SDP,
but was also waiting for something from the first audio packet from the
INVITE system. I mean, if there wasn't a SDP payload, would
rtpproxy been contacted SER, which it obviously did do.
Since the SIP messages seemed, I didn't think to include them,
but here they are (with some numbers obscured) for the same call
that I showed rtpproxy debug for:
The INVITE, as received from the calling party by SER
(monitored on the interface by ngrep)
U 2008/12/04 19:42:20.471166 72.66.211.59:5060 -> 10.81.90.1:5060
INVITE sip:6829995231 at 208.66.49.130 SIP/2.0.
Via: SIP/2.0/UDP 72.66.211.59:5060;branch=z9hG4bK230c41c1;rport.
From: "TROUBLESHOOTING 1000" <sip:4692221700 at 72.66.211.59>;tag=as3257bf0a.
To: <sip:6829995231 at 208.66.49.130>.
Contact: <sip:4692221700 at 72.66.211.59>.
Call-ID: 565aabb151708c9c46c744d2400a454b at 72.66.211.59.
CSeq: 102 INVITE.
User-Agent: Asterisk PBX.
Max-Forwards: 70.
Date: Thu, 04 Dec 2008 19:42:22 GMT.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY.
Supported: replaces.
Content-Type: application/sdp.
Content-Length: 415.
.
v=0.
o=root 58770 58770 IN IP4 72.66.211.59.
s=session.
c=IN IP4 72.66.211.59.
t=0 0.
m=audio 19994 RTP/AVP 0 3 8 112 5 10 7 97 111.
a=rtpmap:0 PCMU/8000.
a=rtpmap:3 GSM/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:112 AAL2-G726-32/8000.
a=rtpmap:5 DVI4/8000.
a=rtpmap:10 L16/8000.
a=rtpmap:7 LPC/8000.
a=rtpmap:97 iLBC/8000.
a=fmtp:97 mode=30.
a=rtpmap:111 G726-32/8000.
a=silenceSupp:off - - - -.
a=ptime:20.
a=sendrecv.
The responses from the called switch
(monitored on the interface facing the called switch by ngrep)
U 2008/12/04 19:42:20.478463 10.31.0.2:5060 -> 10.31.90.1:5060
SIP/2.0 100 Trying.
Call-ID: 565aabb151708c9c46c744d2400a454b at 72.66.211.59.
CSeq: 102 INVITE.
From: "TROUBLESHOOTING 1000" <sip:4692221700 at 72.66.211.59>;tag=as3257bf0a.
To: <sip:6829995231 at 208.66.49.130>;tag=000a0283+1+4e00002+48ad7f8b.
Via: SIP/2.0/UDP 10.31.90.1;branch=z9hG4bKc44e.8eae2e65.0.
Via: SIP/2.0/UDP 72.66.211.59:5060;branch=z9hG4bK230c41c1;rport=5060.
Server: DC-SIP/2.0.
Content-Length: 0.
.
#
U 2008/12/04 19:42:26.926570 10.31.0.2:5060 -> 10.31.90.1:5060
SIP/2.0 183 Session Progress.
Call-ID: 565aabb151708c9c46c744d2400a454b at 72.66.211.59.
CSeq: 102 INVITE.
From: "TROUBLESHOOTING 1000" <sip:4692221700 at 72.66.211.59>;tag=as3257bf0a.
To: <sip:6829995231 at 208.66.49.130>;tag=000a0283+1+4e00002+48ad7f8b.
Via: SIP/2.0/UDP 10.31.90.1;branch=z9hG4bKc44e.8eae2e65.0.
Via: SIP/2.0/UDP 72.66.211.59:5060;branch=z9hG4bK230c41c1;rport=5060.
Server: DC-SIP/2.0.
Contact: <sip:6829995231 at 10.31.0.2>.
Content-Type: application/sdp.
Content-Length: 173.
.
v=0
o=- 3437408546 3437408606 IN IP4 10.31.0.2
s=-
c=IN IP4 10.31.168.2
t=0 0
m=audio 16004 RTP/AVP 0
a=sendrecv
a=ptime:20
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -
#
U 2008/12/04 19:42:37.176531 10.31.0.2:5060 -> 10.31.90.1:5060
SIP/2.0 200 OK.
Call-ID: 565aabb151708c9c46c744d2400a454b at 72.66.211.59.
CSeq: 102 INVITE.
From: "TROUBLESHOOTING 1000" <sip:4692221700 at 72.66.211.59>;tag=as3257bf0a.
To: <sip:6829995231 at 208.66.49.130>;tag=000a0283+1+4e00002+48ad7f8b.
Via: SIP/2.0/UDP 10.31.90.1;branch=z9hG4bKc44e.8eae2e65.0.
Via: SIP/2.0/UDP 72.66.211.59:5060;branch=z9hG4bK230c41c1;rport=5060.
Server: DC-SIP/2.0.
Contact: <sip:6829995231 at 10.31.0.2>.
Content-Type: application/sdp.
Content-Length: 173.
.
v=0
o=- 3437408546 3437408606 IN IP4 10.31.0.2
s=-
c=IN IP4 10.31.168.2
t=0 0
m=audio 16004 RTP/AVP 0
a=sendrecv
a=ptime:20
a=rtpmap:0 PCMU/8000
a=silenceSupp:off - - - -
Don't forget that SER is altering the IP addresses
prior to rtpproxy seeing them and before they are emitted to
the other party, so don't let that throw you. Take my word
that all the IP address substitutions are correct and are
handling calls fine.
Now it sounds like there is some bit of code that is
getting skipped or doesn't work right when you use
rtpproxy in the mode with two interfaces like I am. Is
anybody else using that mode? Maybe the reason no one
else is seeing the audio issue is because they only use one
interface and the code path is different.
Based on this area of interest in the code, I added some
quick debug to rtpproxy and here are the results for
a normal call, where the caller is sending audio as soon
as the 183 or 200 arrives and audio flows more or less
normally:
received command "UE 0d9e8dfd12c8df171a33919e2a536894 at 72.66.211.59
72.66.211.59 15804 as5c0532d5;1"^M
new session 0d9e8dfd12c8df171a33919e2a536894 at 72.66.211.59, tag
as5c0532d5;1 requested, type strong
new session on a port 35000 created, tag as5c0532d5;1
C1
C2
C5
C6
C9
sending reply "35000 10.31.168.18
"
received command "L 0d9e8dfd12c8df171a33919e2a536894 at 72.66.211.59
10.31.0.2 25006 as5c0532d5;1 000a0283+1+4d70
003+5a436147"
lookup on ports 35000/35000, session timer restarted
C1
C2
C5
C6
C9
sending reply "35000 10.81.168.2
"
Now, as you say the "pre-fill" message didn't come out, so
note which log messages were emitted and note that the code
flowed around the section that would do the pre-fill ("C3").
Other than adding the rtpp_log_write calls and maybe
a brace pair to get it within the same conditional,
the code is stock.
...
writeport:
rtpp_log_write(RTPP_LOG_INFO, sp->log,"C1");
if (pidx >= 0) {
if (ia[0] != NULL && ia[1] != NULL) {
rtpp_log_write(RTPP_LOG_INFO, sp->log,"C2");
/*
* Unless the address provided by client historically
* cannot be trusted and address is different from one
* that we recorded update it.
*/
if (spa->untrusted_addr == 0 && !(spa->addr[pidx] != NULL &&
SA_LEN(ia[0]) == SA_LEN(spa->addr[pidx]) &&
memcmp(ia[0], spa->addr[pidx], SA_LEN(ia[0])) == 0)) {
rtpp_log_write(RTPP_LOG_INFO, sp->log,"C3");
rtpp_log_write(RTPP_LOG_INFO, spa->log, "pre-filling
%s's address "
"with %s:%s", (pidx == 0) ? "callee" : "caller", addr,
port);
if (spa->addr[pidx] != NULL)
free(spa->addr[pidx]);
spa->addr[pidx] = ia[0];
ia[0] = NULL;
}
if (spa->rtcp->untrusted_addr == 0 &&
!(spa->rtcp->addr[pidx] != NULL &&
SA_LEN(ia[1]) == SA_LEN(spa->rtcp->addr[pidx]) &&
memcmp(ia[1], spa->rtcp->addr[pidx], SA_LEN(ia[1])) == 0)) {
rtpp_log_write(RTPP_LOG_INFO, sp->log,"C4");
if (spa->rtcp->addr[pidx] != NULL)
free(spa->rtcp->addr[pidx]);
spa->rtcp->addr[pidx] = ia[1];
ia[1] = NULL;
}
}
rtpp_log_write(RTPP_LOG_INFO, sp->log,"C5");
spa->asymmetric[pidx] = spa->rtcp->asymmetric[pidx] = asymmetric;
spa->canupdate[pidx] = spa->rtcp->canupdate[pidx] = NOT(asymmetric);
if (request != 0 || response != 0) {
rtpp_log_write(RTPP_LOG_INFO, sp->log,"C6");
if (requested_nsamples > 0) {
rtpp_log_write(RTPP_LOG_INFO, sp->log,"C7");
rtpp_log_write(RTPP_LOG_INFO, spa->log, "RTP packets
from %s "
"will be resized to %d milliseconds",
(pidx == 0) ? "callee" : "caller", requested_nsamples
/ 8);
} else if (spa->resizers[pidx].output_nsamples > 0) {
rtpp_log_write(RTPP_LOG_INFO, sp->log,"C8");
rtpp_log_write(RTPP_LOG_INFO, spa->log, "Resizing of RTP "
"packets from %s has been disabled",
(pidx == 0) ? "callee" : "caller");
}
spa->resizers[pidx].output_nsamples = requested_nsamples;
}
}
for (i = 0; i < 2; i++)
if (ia[i] != NULL)
free(ia[i]);
cp = buf;
len = 0;
if (cookie != NULL) {
len = sprintf(cp, "%s ", cookie);
cp += len;
}
if (lia[0] == NULL || ishostnull(lia[0]))
len += sprintf(cp, "%d\n", lport);
else
len += sprintf(cp, "%d %s%s\n", lport, addr2char(lia[0]),
(lia[0]->sa_family == AF_INET) ? "" : " 6");
rtpp_log_write(RTPP_LOG_INFO, sp->log,"C9");
doreply:
doreply();
return 0;
...
So, something in this "if" didn't allow the pre-fill to occur:
if (spa->untrusted_addr == 0 && !(spa->addr[pidx] != NULL &&
SA_LEN(ia[0]) == SA_LEN(spa->addr[pidx]) &&
memcmp(ia[0], spa->addr[pidx], SA_LEN(ia[0])) == 0)) {
I'll add some additional debugging later and see if I can spot
which of those conditions is the guilty party or parties.
More information about the sr-users
mailing list