[Serusers] SER has problems matching ACKs to replies
Maxim Sobolev
sobomax at portaone.com
Tue Apr 8 18:26:54 CEST 2003
Not only that, but there is also a bug which causes match failure
due to extra space in the ACK, see the gdb session below:
0x2a17b904 in t_lookup_request (p_msg=0x80d4c88, leave_new_locked=1) at t_lookup.c:268
268 {int b=1; while (b);}
(gdb) s b=0
(gdb) n
270 if (!EQ_LEN(callid)) continue;
(gdb) print t_msg->callid->body
$8 = {
s = 0x282ed9b8 "3650497277 at 192.168.1.20\r\nCSeq: 2 INVITE\r\nContact: <sip:380442466396 at 192.168.1.
20:5060;user=phone;transport=udp>\r\nUser-Agent: Cisco ATA 186 v2.15 ata18x (030401b)\r\nAuthorizat
ion: Digest username=\"3804"..., len = 23}
(gdb) print p_msg->callid->body
$9 = {s = 0x80bdf73 " 3650497277 at 192.168.1.20\r", len = 24}
As you can see, the callid is the same, but EQ_LEN(callid) will be
false, due to the fact that p_msg->callid->body.len != t_msg->callid->body.len.
-Maxim
On Tue, Apr 08, 2003 at 05:56:17PM +0300, Maxim Sobolev wrote:
> Sorry, further investigation shown that this particular problem was
> caused by the typo in our fix for hashing function (one found in 0.8.10
> didn't bother to strip insignificant chars from call-id and cseq number).
> I've fixed that and the problem gone.
>
> However, we have another problem with ACK matching. The problem is that
> we are using propiertary module which queries billing engine via Radius
> and uses its replies to rewrite URI. Since it isn't practical to run
> that query on each request received, we are only performing it on
> INVITEs, which is fine as long as the next hop is always B2BUA that
> only cares about method URI in INVITE requests and ignores it in any
> subsequent requests. The typical sequence looks like the following:
>
> 1. ATA->SER:
>
> INVITE xyz at foo.bar
>
> 2. SER->BILLING
>
> please expand xyz
>
> 3. BILLING->SER
>
> xyz expands to 123456
>
> 4. SER->B2BUA (t_relay_to())
>
> INVITE 123456 at foo.bar
>
> Everything is fine when INVITE transaction ends with a 200 OK, in this
> case ATA generates ACK to acknowelege 200 OK using information from
> that 200 OK, i.e. `ACK 123456 at foo.bar', not `ACK xyz at foo.bar'. The problem
> happens if transaction ends with 4xx error, or is cancelled by the
> originating party, in this case ATA acknoweleges receipt of final negative
> response with `ACK xyz at foo.bar' so that tm module is unable to match ACK
> to original INVITE.
>
> Do you have any ideas how to properly solve this problem without
> introducing steps (2) and (3) above for every ACK request as well?
> It would be inacceptable for us since each BILLING query means
> extra database access, therefore is puting extra load on the system
> and degrading its performance (normal call involves 2 ACKs, so that
> there would be 3 db accesses instead of 1).
>
> I think that it should be possible to resolve the problem by modifying
> tm module to match ACKs for non-200 replies to original uri in INVITE
> instead to rewriten one. What do you think? Is there any potential
> problems with this approach?
>
> -Maxim
>
> On Mon, Apr 07, 2003 at 10:41:31PM +0200, Jiri Kuthan wrote:
> > Maxim,
> >
> > neither did I find a reason why the ACK is not matched. I might be
> > wrong but my guess is that it is a config issue -- are you sure it
> > enters t_relay in your script?
> >
> > -Jiri
> >
> > At 09:19 PM 4/7/2003, Maxim Sobolev wrote:
> > >Folks,
> > >
> > >I found that in the stateful mode, SER is having troubles matching
> > >ACKs to negative replies when Vovida B2BUA (1.5.0) is used as one
> > >UA, while Cisco ATA 186 as another one. Following is a dump of the
> > >session illustrating the problem. As you can see, SER keeps
> > >retransmiting 480, despite receiving properly formed ACKs. Does
> > >anybody have any ideas what the problem might be?
> > >
> > >-Maxim
> > >P.S. I am also seeing in the logs the following warnings:
> > >
> > >Apr 7 12:05:28 demo ser[86090]: WARNING: sip_msg_cloner: header body ignored: 4096
> > >
> > >
> > >B2BUA->SER
> > >
> > >INVITE sip:16045215277 at demo.portaone.com:5060;transport=udp;user=phone SIP/2.0
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >To: <sip:121 at 64.180.102.72;user=phone>
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >Call-ID: 3135130751 at 192.168.1.20
> > >cisco-GUID: 200546447-2237180178-1764455078-2518034476
> > >CSeq: 2 INVITE
> > >Max-Forwards: 10
> > >Expires: 300
> > >Contact: <sip:380442466396 at 64.180.102.72:5061;user=phone>
> > >User-Agent: PortaSIP (030401b)
> > >Content-Type: application/sdp
> > >Content-Length: 309
> > >o=380442466396 20916528 20916528 IN IP4 192.168.1.20
> > >s=ATA186 Call
> > >c=IN IP4 193.111.9.226
> > >t=0 0
> > >m=audio 14000 RTP/AVP 4 8 0 101
> > >a=rtpmap:4 G723/8000/1
> > >a=rtpmap:8 PCMA/8000/1
> > >a=rtpmap:0 PCMU/8000/1
> > >a=rtpmap:101 telephone-event/8000
> > >a=fmtp:101 0-15
> > >a=direction:active
> > >a=oldmediaip:192.168.1.20
> > >
> > >SER->B2BUA
> > >
> > >SIP/2.0 100 trying -- your call is important to us
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >To: <sip:121 at 64.180.102.72;user=phone>
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 INVITE
> > >Server: Sip EXpress router (0.8.10 (i386/freebsd))
> > >Content-Length: 0
> > >
> > >SER->ATA
> > >
> > >INVITE sip:16045215277 at 172.17.1.127:5060;user=phone;transport=udp SIP/2.0
> > >Record-Route: <sip:16045215277 at 64.180.102.72;branch=0>
> > >Via: SIP/2.0/UDP 64.180.102.72;branch=z9hG4bK56f9.3c3c97acad0bdb329284be13e26ccc54.0
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >To: <sip:121 at 64.180.102.72;user=phone>
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >Call-ID: 3135130751 at 192.168.1.20
> > >cisco-GUID: 200546447-2237180178-1764455078-2518034476
> > >CSeq: 2 INVITE
> > >Max-Forwards: 9
> > >Expires: 300
> > >Contact: <sip:380442466396 at 64.180.102.72:5061;user=phone>
> > >User-Agent: PortaSIP (030401b)
> > >Content-Type: application/sdp
> > >Content-Length: 309
> > >o=380442466396 20916528 20916528 IN IP4 192.168.1.20
> > >s=ATA186 Call
> > >c=IN IP4 193.111.9.226
> > >t=0 0
> > >m=audio 14000 RTP/AVP 4 8 0 101
> > >a=rtpmap:4 G723/8000/1
> > >a=rtpmap:8 PCMA/8000/1
> > >a=rtpmap:0 PCMU/8000/1
> > >a=rtpmap:101 telephone-event/8000
> > >a=fmtp:101 0-15
> > >a=direction:active
> > >a=oldmediaip:192.168.1.20
> > >
> > >ATA->SER
> > >
> > >SIP/2.0 100 Trying
> > >Via: SIP/2.0/UDP 64.180.102.72;branch=z9hG4bK56f9.3c3c97acad0bdb329284be13e26ccc54.0
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >To: <sip:121 at 64.180.102.72;user=phone>;tag=2698540533
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 INVITE
> > >Server: Cisco ATA 186 v2.15 ata18x (030401b)
> > >Content-Length: 0
> > >
> > >ATA->SER
> > >
> > >SIP/2.0 183 Session Progress
> > >Via: SIP/2.0/UDP 64.180.102.72;branch=z9hG4bK56f9.3c3c97acad0bdb329284be13e26ccc54.0
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >To: <sip:121 at 64.180.102.72;user=phone>;tag=2698540533
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 INVITE
> > >Server: Cisco ATA 186 v2.15 ata18x (030401b)
> > >Content-Length: 201
> > >Content-Type: application/sdp
> > >o=16045215277 1110 1110 IN IP4 172.17.1.127
> > >s=ATA186 Call
> > >c=IN IP4 64.180.102.72
> > >t=0 0
> > >m=audio 10000 RTP/AVP 4 101
> > >a=rtpmap:4 G723/8000/1
> > >a=rtpmap:101 telephone-event/8000
> > >a=fmtp:101 0-15
> > >
> > >SER->B2BUA
> > >
> > >SIP/2.0 183 Session Progress
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >To: <sip:121 at 64.180.102.72;user=phone>;tag=2698540533
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 INVITE
> > >Server: Cisco ATA 186 v2.15 ata18x (030401b)
> > >Content-Length: 221
> > >Content-Type: application/sdp
> > >o=16045215277 1110 1110 IN IP4 172.17.1.127
> > >s=ATA186 Call
> > >c=IN IP4 64.180.102.72
> > >t=0 0
> > >m=audio 10000 RTP/AVP 4 101
> > >a=rtpmap:4 G723/8000/1
> > >a=rtpmap:101 telephone-event/8000
> > >a=fmtp:101 0-15
> > >a=direction:active
> > >
> > >ATA->SER
> > >
> > >SIP/2.0 480 Temporarily Not Available
> > >Via: SIP/2.0/UDP 64.180.102.72;branch=z9hG4bK56f9.3c3c97acad0bdb329284be13e26ccc54.0
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >To: <sip:121 at 64.180.102.72;user=phone>;tag=2698540533
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 INVITE
> > >Server: Cisco ATA 186 v2.15 ata18x (030401b)
> > >Content-Length: 0
> > >
> > >SER->B2BUA
> > >
> > >SIP/2.0 480 Temporarily Not Available
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >To: <sip:121 at 64.180.102.72;user=phone>;tag=2698540533
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 INVITE
> > >Server: Cisco ATA 186 v2.15 ata18x (030401b)
> > >Content-Length: 0
> > >
> > >B2BUA->SER
> > >
> > >ACK sip:16045215277 at demo.portaone.com:5060;transport=udp;user=phone SIP/2.0
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >To: <sip:121 at 64.180.102.72;user=phone>;tag=2698540533
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 ACK
> > >Max-Forwards: 70
> > >Content-Length: 0
> > >
> > >SER->ATA
> > >
> > >ACK sip:16045215277 at 172.17.1.127:5060;user=phone;transport=udp SIP/2.0
> > >Via: SIP/2.0/UDP 64.180.102.72;branch=z9hG4bKbc52.5db2fe1211adfdd0d5db3db6e2295344.0
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >To: <sip:121 at 64.180.102.72;user=phone>;tag=2698540533
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 ACK
> > >Max-Forwards: 69
> > >Content-Length: 0
> > >
> > >SER->B2BUA
> > >
> > >SIP/2.0 480 Temporarily Not Available
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >To: <sip:121 at 64.180.102.72;user=phone>;tag=2698540533
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 INVITE
> > >Server: Cisco ATA 186 v2.15 ata18x (030401b)
> > >Content-Length: 0
> > >
> > >B2BUA->SER
> > >
> > >ACK sip:16045215277 at demo.portaone.com:5060;transport=udp;user=phone SIP/2.0
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >To: <sip:121 at 64.180.102.72;user=phone>;tag=2698540533
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 ACK
> > >Max-Forwards: 70
> > >Content-Length: 0
> > >
> > >SER->ATA
> > >
> > >ACK sip:16045215277 at 172.17.1.127:5060;user=phone;transport=udp SIP/2.0
> > >Via: SIP/2.0/UDP 64.180.102.72;branch=z9hG4bKbc52.5db2fe1211adfdd0d5db3db6e2295344.0
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >To: <sip:121 at 64.180.102.72;user=phone>;tag=2698540533
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 ACK
> > >Max-Forwards: 69
> > >Content-Length: 0
> > >
> > >SER->B2BUA
> > >
> > >SIP/2.0 480 Temporarily Not Available
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >To: <sip:121 at 64.180.102.72;user=phone>;tag=2698540533
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 INVITE
> > >Server: Cisco ATA 186 v2.15 ata18x (030401b)
> > >Content-Length: 0
> > >
> > >B2BUA->SER
> > >
> > >ACK sip:16045215277 at demo.portaone.com:5060;transport=udp;user=phone SIP/2.0
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >To: <sip:121 at 64.180.102.72;user=phone>;tag=2698540533
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 ACK
> > >Max-Forwards: 70
> > >Content-Length: 0
> > >
> > >SER->ATA
> > >
> > >ACK sip:16045215277 at 172.17.1.127:5060;user=phone;transport=udp SIP/2.0
> > >Via: SIP/2.0/UDP 64.180.102.72;branch=z9hG4bKbc52.5db2fe1211adfdd0d5db3db6e2295344.0
> > >Via: SIP/2.0/UDP 64.180.102.72:5061
> > >To: <sip:121 at 64.180.102.72;user=phone>;tag=2698540533
> > >From: <sip:380442466396 at 64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904
> > >Call-ID: 3135130751 at 192.168.1.20
> > >CSeq: 2 ACK
> > >Max-Forwards: 69
> > >Content-Length: 0
> > >
> > >[the last 3 repeat until timeout hits]
> > >_______________________________________________
> > >Serusers mailing list
> > >serusers at lists.iptel.org
> > >http://lists.iptel.org/mailman/listinfo/serusers
> >
> > --
> > Jiri Kuthan http://iptel.org/~jiri/
> _______________________________________________
> Serusers mailing list
> serusers at lists.iptel.org
> http://lists.iptel.org/mailman/listinfo/serusers
More information about the sr-users
mailing list