Wednesday, February 20, 2008

Missing SIP traffic?

SIP can be cool because it resembles HTTP. OpenSER and SER are cool because they are so powerful. For instance, in OpenSER you don't need to authenticate calls. Or you can specify which request URIs should be challenged with an auth (or which method types, like REGISTER). This is usually done like so:

if (is_method("INVITE")) {

if (uri=~"^sip:1000@") {
rewritehostport("192.168.1.1:5060"); #set destination
route(1); #t_relay, etc is in route(1)
}

if (!allow_trusted()) {
if (!proxy_authorize("star2star.com","subscriber")) {
proxy_challenge("star2star.com","0");
return;
} else if (!check_from()) {
sl_send_reply("403", "Use From=ID");
return;
};

xlog("Creds are good\n");
consume_credentials();

};

if (uri=~"^sip:1[0-9]{10}@") {
route(5); #goto LCR
return;
};
};

So, in this example any SIP endpoint that can reach this proxy can hit RURI:1000 and be forwarded to the voicemail server with no authentication. As we step through this example, the only other URIs that match are after the allow_trusted or proxy_authorize checks. Basically, your source IP address has to be in the trusted table or you have to successfully respond to a 407 Proxy Authentication Required from the proxy.

I've seen this work perfectly between an Asterisk client and OpenSER hundreds of times. Most of the time it works. MOST OF THE TIME. I've noticed a scenario where it does not work, and I am struggling to figure out why...

Here's the architecture:

User's Phone -> Asterisk --(internet)--> OpenSER -> Misc. other systems

Like I said, normally this works and it looks like this (get ready for some SIP):

#
U a.b.c.d:5060 -> e.f.g.h:5060
INVITE sip:9415551212@e.f.g.h SIP/2.0.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK2e8b0432;rport.
From: "User Phone" ;tag=as3474f6c4.
To: .
Contact: .
Call-ID: 2ad4212700f61c3e1294439f1c72c479@a.b.c.d.
CSeq: 102 INVITE.
User-Agent: Asterisk PBX.
Max-Forwards: 70.
Remote-Party-ID: "User Phone" ;privacy=off;screen=no.
Date: Tue, 05 Feb 2008 18:24:11 GMT.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY.
X-s2s-region: 1.
Content-Type: application/sdp.
Content-Length: 216.
.
v=0.
o=root 1429 1429 IN IP4 a.b.c.d.
s=session.
c=IN IP4 a.b.c.d.
t=0 0.
m=audio 19424 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=silenceSupp:off - - - -.

#
U e.f.g.h:5060 -> a.b.c.d:5060
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK2e8b0432;rport=5060.
From: "User Phone" ;tag=as3474f6c4.
To: .
Call-ID: 2ad4212700f61c3e1294439f1c72c479@a.b.c.d.
CSeq: 102 INVITE.
Server: OpenSer (1.1.0-notls (i386/linux)).
Content-Length: 0.
Warning: 392 e.f.g.h:5060 "Noisy feedback tells: pid=4363 req_src_ip=a.b.c.d req_src_port=5060 in_uri=sip:9415551212@e.f.g.h out_uri=sip:9415551212@e.f.g.h via_cnt==1".
.

#
U e.f.g.h:5060 -> a.b.c.d:5060
SIP/2.0 407 Proxy Authentication Required.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK2e8b0432;rport=5060.
From: "User Phone" ;tag=as3474f6c4.
To: ;tag=0dd4490c85a9eb8d48ff967a8700cef0.fcb4.
Call-ID: 2ad4212700f61c3e1294439f1c72c479@a.b.c.d.
CSeq: 102 INVITE.
Proxy-Authenticate: Digest realm="star2star.com", nonce="valid_nonce".
Server: OpenSer (1.1.0-notls (i386/linux)).
Content-Length: 0.
Warning: 392 e.f.g.h:5060 "Noisy feedback tells: pid=4363 req_src_ip=a.b.c.d req_src_port=5060 in_uri=sip:9415551212@e.f.g.h out_uri=sip:9415551212@e.f.g.h via_cnt==1".
.

#
U a.b.c.d:5060 -> e.f.g.h:5060
ACK sip:9415551212@e.f.g.h SIP/2.0.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK2e8b0432;rport.
From: "User Phone" ;tag=as3474f6c4.
To: ;tag=0dd4490c85a9eb8d48ff967a8700cef0.fcb4.
Contact: .
Call-ID: 2ad4212700f61c3e1294439f1c72c479@a.b.c.d.
CSeq: 102 ACK.
User-Agent: Asterisk PBX.
Max-Forwards: 70.
Remote-Party-ID: "User Phone" ;privacy=off;screen=no.
Content-Length: 0.
.

#
U a.b.c.d:5060 -> e.f.g.h:5060
INVITE sip:9415551212@e.f.g.h SIP/2.0.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK57af1f44;rport.
From: "User Phone" ;tag=as3474f6c4.
To: .
Contact: .
Call-ID: 2ad4212700f61c3e1294439f1c72c479@a.b.c.d.
CSeq: 103 INVITE.
User-Agent: Asterisk PBX.
Max-Forwards: 70.
Remote-Party-ID: "User Phone" ;privacy=off;screen=no.
Proxy-Authorization: Digest username="cpesource", realm="star2star.com", algorithm=MD5, uri="sip:9415551212@e.f.g.h", nonce="valid_nonce", response="valid_response", opaque="".
Date: Tue, 05 Feb 2008 18:24:12 GMT.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY.
X-s2s-region: 1.
Content-Type: application/sdp.
Content-Length: 216.
.
v=0.
o=root 1429 1430 IN IP4 a.b.c.d.
s=session.
c=IN IP4 a.b.c.d.
t=0 0.
m=audio 19424 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=silenceSupp:off - - - -.

#
U e.f.g.h:5060 -> a.b.c.d:5060
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK57af1f44;rport=5060.
From: "User Phone" ;tag=as3474f6c4.
To: .
Call-ID: 2ad4212700f61c3e1294439f1c72c479@a.b.c.d.
CSeq: 103 INVITE.
Server: OpenSer (1.1.0-notls (i386/linux)).
Content-Length: 0.
Warning: 392 e.f.g.h:5060 "Noisy feedback tells: pid=4361 req_src_ip=a.b.c.d req_src_port=5060 in_uri=sip:9415551212@e.f.g.h out_uri=sip:9415551212@e.f.g.h via_cnt==1".
.

#
U e.f.g.h:5060 -> a.b.c.d:5060
SIP/2.0 100 trying -- your call is important to us.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK57af1f44;rport=5060.
From: "User Phone" ;tag=as3474f6c4.
To: .
Call-ID: 2ad4212700f61c3e1294439f1c72c479@a.b.c.d.
CSeq: 103 INVITE.
Server: OpenSer (1.1.0-notls (i386/linux)).
Content-Length: 0.
Warning: 392 e.f.g.h:5060 "Noisy feedback tells: pid=4361 req_src_ip=a.b.c.d req_src_port=5060 in_uri=sip:9415551212@e.f.g.h out_uri=sip:18135551212@w.x.y.z:5060;transport=udp via_cnt==1".
.

#
U e.f.g.h:5060 -> a.b.c.d:5060
SIP/2.0 183 Session Progress.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK57af1f44;rport=5060.
From: "User Phone" ;tag=as3474f6c4.
To: ;tag=F6697AC-1DCD.
Date: Tue, 05 Feb 2008 18:24:12 GMT.
Call-ID: 2ad4212700f61c3e1294439f1c72c479@a.b.c.d.
Server: Cisco-SIPGateway/IOS-12.x.
CSeq: 103 INVITE.
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER.
Allow-Events: telephone-event.
Contact: .
Record-Route: .
Content-Disposition: session;handling=required.
Content-Type: application/sdp.
Content-Length: 238.
.
v=0.
o=CiscoSystemsSIP-GW-UserAgent 2171 1394 IN IP4 w.x.y.z.
s=SIP Call.
c=IN IP4 w.x.y.z.
t=0 0.
m=audio 18722 RTP/AVP 0 101.
c=IN IP4 w.x.y.z.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.

#
U e.f.g.h:5060 -> a.b.c.d:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK57af1f44;rport=5060.
From: "User Phone" ;tag=as3474f6c4.
To: ;tag=F6697AC-1DCD.
Date: Tue, 05 Feb 2008 18:24:12 GMT.
Call-ID: 2ad4212700f61c3e1294439f1c72c479@a.b.c.d.
Server: Cisco-SIPGateway/IOS-12.x.
CSeq: 103 INVITE.
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, COMET, REFER, SUBSCRIBE, NOTIFY, INFO, UPDATE, REGISTER.
Allow-Events: telephone-event.
Contact: .
Record-Route: .
Content-Type: application/sdp.
Content-Length: 238.
.
v=0.
o=CiscoSystemsSIP-GW-UserAgent 2171 1394 IN IP4 w.x.y.z.
s=SIP Call.
c=IN IP4 w.x.y.z.
t=0 0.
m=audio 18722 RTP/AVP 0 101.
c=IN IP4 w.x.y.z.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.

#
U a.b.c.d:5060 -> e.f.g.h:5060
ACK sip:18135551212@w.x.y.z:5060 SIP/2.0.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK38cd41fe;rport.
Route: .
From: "User Phone" ;tag=as3474f6c4.
To: ;tag=F6697AC-1DCD.
Contact: .
Call-ID: 2ad4212700f61c3e1294439f1c72c479@a.b.c.d.
CSeq: 103 ACK.
User-Agent: Asterisk PBX.
Max-Forwards: 70.
Remote-Party-ID: "User Phone" ;privacy=off;screen=no.
Content-Length: 0.
.

#
U a.b.c.d:5060 -> e.f.g.h:5060
BYE sip:18135551212@w.x.y.z:5060 SIP/2.0.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK48cf5abc;rport.
Route: .
From: "User Phone" ;tag=as3474f6c4.
To: ;tag=F6697AC-1DCD.
Call-ID: 2ad4212700f61c3e1294439f1c72c479@a.b.c.d.
CSeq: 104 BYE.
User-Agent: Asterisk PBX.
Max-Forwards: 70.
Remote-Party-ID: "User Phone" ;privacy=off;screen=no.
Proxy-Authorization: Digest username="cpesource", realm="star2star.com", algorithm=MD5, uri="sip:18135551212@w.x.y.z:5060", nonce="valid_nonce", response="valid_response", opaque="".
Content-Length: 0.
.

#
U e.f.g.h:5060 -> a.b.c.d:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK48cf5abc;rport=5060.
From: "User Phone" ;tag=as3474f6c4.
To: ;tag=F6697AC-1DCD.
Date: Tue, 05 Feb 2008 18:24:21 GMT.
Call-ID: 2ad4212700f61c3e1294439f1c72c479@a.b.c.d.
Server: Cisco-SIPGateway/IOS-12.x.
Content-Length: 0.
CSeq: 104 BYE.
.

INVITE comes in, 407 goes out and gets ACKd by remote Asterisk instance, INVITE comes back, this time with a Proxy-Authorization: header attached. The call gets forwarded, setup, and everything is fine.

HOWEVER - some times the 407 doesn't make it back to Asterisk (for whatever reason) and the call dies:

#
U a.b.c.d:5060 -> e.f.g.h:5060
INVITE sip:8135551212@e.f.g.h SIP/2.0.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK3beb8c07;rport.
From: "User Phone" ;tag=as664fbdbc.
To: .
Contact: .
Call-ID: 165e2edb63fd81b30e629055245b8b28@a.b.c.d.
CSeq: 102 INVITE.
User-Agent: Asterisk PBX.
Max-Forwards: 70.
Remote-Party-ID: "User Phone" ;privacy=off;screen=no.
Date: Tue, 05 Feb 2008 18:22:47 GMT.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY.
X-s2s-region: 1.
Content-Type: application/sdp.
Content-Length: 216.
.
v=0.
o=root 1306 1306 IN IP4 a.b.c.d.
s=session.
c=IN IP4 a.b.c.d.
t=0 0.
m=audio 19154 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=silenceSupp:off - - - -.

#
U e.f.g.h:5060 -> a.b.c.d:5060
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK3beb8c07;rport=5060.
From: "User Phone" ;tag=as664fbdbc.
To: .
Call-ID: 165e2edb63fd81b30e629055245b8b28@a.b.c.d.
CSeq: 102 INVITE.
Server: OpenSer (1.1.0-notls (i386/linux)).
Content-Length: 0.
Warning: 392 e.f.g.h:5060 "Noisy feedback tells: pid=4363 req_src_ip=a.b.c.d req_src_port=5060 in_uri=sip:8135551212@e.f.g.h out_uri=sip:8135551212@e.f.g.h via_cnt==1".
.

#
U e.f.g.h:5060 -> a.b.c.d:5060
SIP/2.0 407 Proxy Authentication Required.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK3beb8c07;rport=5060.
From: "User Phone" ;tag=as664fbdbc.
To: ;tag=0dd4490c85a9eb8d48ff967a8700cef0.d2fe.
Call-ID: 165e2edb63fd81b30e629055245b8b28@a.b.c.d.
CSeq: 102 INVITE.
Proxy-Authenticate: Digest realm="star2star.com", nonce="valid_nonce".
Server: OpenSer (1.1.0-notls (i386/linux)).
Content-Length: 0.
Warning: 392 e.f.g.h:5060 "Noisy feedback tells: pid=4363 req_src_ip=a.b.c.d req_src_port=5060 in_uri=sip:8135551212@e.f.g.h out_uri=sip:8135551212@e.f.g.h via_cnt==1".
.

#
U a.b.c.d:5060 -> e.f.g.h:5060
CANCEL sip:8135551212@e.f.g.h SIP/2.0.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK3beb8c07;rport.
From: "User Phone" ;tag=as664fbdbc.
To: .
Call-ID: 165e2edb63fd81b30e629055245b8b28@a.b.c.d.
CSeq: 102 CANCEL.
User-Agent: Asterisk PBX.
Max-Forwards: 70.
Remote-Party-ID: "User Phone" ;privacy=off;screen=no.
Content-Length: 0.
.

#
U e.f.g.h:5060 -> a.b.c.d:5060
SIP/2.0 483 Too Many Hops.
Via: SIP/2.0/UDP a.b.c.d:5060;branch=z9hG4bK3beb8c07;rport=5060.
From: "User Phone" ;tag=as664fbdbc.
To: ;tag=0dd4490c85a9eb8d48ff967a8700cef0.f74a.
Call-ID: 165e2edb63fd81b30e629055245b8b28@a.b.c.d.
CSeq: 102 CANCEL.
Server: OpenSer (1.1.0-notls (i386/linux)).
Content-Length: 0.
Warning: 392 e.f.g.h:5060 "Noisy feedback tells: pid=4365 req_src_ip=e.f.g.h req_src_port=5060 in_uri=sip:8135551212@e.f.g.h out_uri=sip:8135551212@e.f.g.h via_cnt==71".
.


So, in this scenario the INVITE comes in and OpenSER responds with a 407. The remote endpoint (Asterisk) never receives the 407, gives up on the request, sending a CANCEL after about 60 seconds. At this point I'm not really sure what happens but something loops in OpenSER until Max-Forwards: is exceeded.

We can verify from packet captures on the remote Asterisk system that the 407 is not being received and therefore, Asterisk isn't resending the INVITE with auth.

What's doing on here? We're not seeing any other messages being lost, we're not seeing packet loss, what's going on?

No comments: