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(a)foo.bar 2. SER->BILLING please expand xyz 3. BILLING->SER xyz expands to 123456 4. SER->B2BUA (t_relay_to()) INVITE 123456(a)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(a)foo.bar'#39;, not `ACK xyz(a)foo.bar'#39;. 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(a)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: _______________________________________________ Serusers mailing list serusers(a)lists.iptel.org http://lists.iptel.org/mailman/listinfo/serusers

Yet another obstacle on the way of proper INVITE-ACK matching for negative replies: some UA might pick up Via parameters from provisional responses and then copy them into ACK. For example ATA-186 does this with received/rport parameters, so that they don't match with ones from INVITE: (gdb) print t_msg->via1->name $18 = { s = 0x282ed926 "SIP/2.0/UDP 192.168.1.20:5060\r\nFrom: <sip:380442466396@64.180.102.72;user=phone> ;tag=3473403119\r\nTo: <sip:122@64.180.102.72;user=phone>\r\nCall-ID: 3487919719(a)192.168.1.20\r\nCSe q: 2 INVITE\r\nContact: <sip"..., len = 3} (gdb) print p_msg->orig $19 = 0x80d51f8 "ACK sip:122@64.180.102.72;user=phone SIP/2.0\r\nVia: SIP/2.0/UDP 192.168.1.20:5060; rport=5060;received=193.111.9.226\r\nFrom: <sip:380442466396@64.180.102.72;user=phone>;tag=347340311 9\r\nTo: <sip:122@64.18"... As you can see, in the INVITE we had 1st Via: SIP/2.0/UDP 192.168.1.20:5060 While in the ACK: SIP/2.0/UDP 192.168.1.20:5060;rport=5060;received=193.111.9.226 Needs to be corrected as well. -Maxim On Tue, Apr 08, 2003 at 07:26:54PM +0300, Maxim Sobolev wrote: _______________________________________________ Serusers mailing list serusers(a)lists.iptel.org http://lists.iptel.org/mailman/listinfo/serusers

Yet another obstacle on the way of proper INVITE-ACK matching for negative replies: some UA might pick up Via parameters from provisional responses and then copy them into ACK.

INV: SIP/2.0/UDP 192.168.1.20:5060 ACK: SIP/2.0/UDP 192.168.1.20:5060;rport=5060;received=193.111.9.22

For example ATA-186 does this with received/rport parameters, so that they don't match with ones from INVITE: (gdb) print t_msg->via1->name $18 = { s = 0x282ed926 "SIP/2.0/UDP 192.168.1.20:5060\r\nFrom: <sip:380442466396@64.180.102.72;user=phone> ;tag=3473403119\r\nTo: <sip:122@64.180.102.72;user=phone>\r\nCall-ID: 3487919719(a)192.168.1.20\r\nCSe q: 2 INVITE\r\nContact: <sip"..., len = 3} (gdb) print p_msg->orig $19 = 0x80d51f8 "ACK sip:122@64.180.102.72;user=phone SIP/2.0\r\nVia: SIP/2.0/UDP 192.168.1.20:5060; rport=5060;received=193.111.9.226\r\nFrom: <sip:380442466396@64.180.102.72;user=phone>;tag=347340311 9\r\nTo: <sip:122@64.18"... As you can see, in the INVITE we had 1st Via: SIP/2.0/UDP 192.168.1.20:5060 While in the ACK: SIP/2.0/UDP 192.168.1.20:5060;rport=5060;received=193.111.9.226 Needs to be corrected as well. -Maxim On Tue, Apr 08, 2003 at 07:26:54PM +0300, Maxim Sobolev wrote: > 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 &quot;3650497277(a)192.168.1.20\r\nCSeqnCSeq: 2 INVITE\r\nContact: <sip:380442466396@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(a)192.168.1.20\r&quot;quot;, 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(a)foo.bar > > > > 2. SER->BILLING > > > > please expand xyz > > > > 3. BILLING->SER > > > > xyz expands to 123456 > > > > 4. SER->B2BUA (t_relay_to()) > > > > INVITE 123456(a)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(a)foo.bar&#39;#39;, not `ACK xyz(a)foo.bar&#39;#39;. 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(a)foo.bar&#39; 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@demo.portaone.com:5060;transport=udp;user=phone SIP/2.0 > > > >Via: SIP/2.0/UDP 64.180.102.72:5061 > > > >To: <sip:121@64.180.102.72;user=phone> > > > >From: <sip:380442466396@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >Call-ID: 3135130751(a)192.168.1.20 > > > >cisco-GUID: 200546447-2237180178-1764455078-2518034476 > > > >CSeq: 2 INVITE > > > >Max-Forwards: 10 > > > >Expires: 300 > > > >Contact: <sip:380442466396@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@64.180.102.72;user=phone> > > > >From: <sip:380442466396@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >Call-ID: 3135130751(a)192.168.1.20 > > > >CSeq: 2 INVITE > > > >Server: Sip EXpress router (0.8.10 (i386/freebsd)) > > > >Content-Length: 0 > > > > > > > >SER->ATA > > > > > > > >INVITE sip:16045215277@172.17.1.127:5060;user=phone;transport=udp SIP/2.0 > > > >Record-Route: <sip:16045215277@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@64.180.102.72;user=phone> > > > >From: <sip:380442466396@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >Call-ID: 3135130751(a)192.168.1.20 > > > >cisco-GUID: 200546447-2237180178-1764455078-2518034476 > > > >CSeq: 2 INVITE > > > >Max-Forwards: 9 > > > >Expires: 300 > > > >Contact: <sip:380442466396@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@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >To: <sip:121@64.180.102.72;user=phone>;tag=2698540533 > > > >Call-ID: 3135130751(a)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@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >To: <sip:121@64.180.102.72;user=phone>;tag=2698540533 > > > >Call-ID: 3135130751(a)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@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >To: <sip:121@64.180.102.72;user=phone>;tag=2698540533 > > > >Call-ID: 3135130751(a)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@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >To: <sip:121@64.180.102.72;user=phone>;tag=2698540533 > > > >Call-ID: 3135130751(a)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@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >To: <sip:121@64.180.102.72;user=phone>;tag=2698540533 > > > >Call-ID: 3135130751(a)192.168.1.20 > > > >CSeq: 2 INVITE > > > >Server: Cisco ATA 186 v2.15 ata18x (030401b) > > > >Content-Length: 0 > > > > > > > >B2BUA->SER > > > > > > > >ACK sip:16045215277@demo.portaone.com:5060;transport=udp;user=phone SIP/2.0 > > > >Via: SIP/2.0/UDP 64.180.102.72:5061 > > > >To: <sip:121@64.180.102.72;user=phone>;tag=2698540533 > > > >From: <sip:380442466396@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >Call-ID: 3135130751(a)192.168.1.20 > > > >CSeq: 2 ACK > > > >Max-Forwards: 70 > > > >Content-Length: 0 > > > > > > > >SER->ATA > > > > > > > >ACK sip:16045215277@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@64.180.102.72;user=phone>;tag=2698540533 > > > >From: <sip:380442466396@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >Call-ID: 3135130751(a)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@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >To: <sip:121@64.180.102.72;user=phone>;tag=2698540533 > > > >Call-ID: 3135130751(a)192.168.1.20 > > > >CSeq: 2 INVITE > > > >Server: Cisco ATA 186 v2.15 ata18x (030401b) > > > >Content-Length: 0 > > > > > > > >B2BUA->SER > > > > > > > >ACK sip:16045215277@demo.portaone.com:5060;transport=udp;user=phone SIP/2.0 > > > >Via: SIP/2.0/UDP 64.180.102.72:5061 > > > >To: <sip:121@64.180.102.72;user=phone>;tag=2698540533 > > > >From: <sip:380442466396@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >Call-ID: 3135130751(a)192.168.1.20 > > > >CSeq: 2 ACK > > > >Max-Forwards: 70 > > > >Content-Length: 0 > > > > > > > >SER->ATA > > > > > > > >ACK sip:16045215277@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@64.180.102.72;user=phone>;tag=2698540533 > > > >From: <sip:380442466396@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >Call-ID: 3135130751(a)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@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >To: <sip:121@64.180.102.72;user=phone>;tag=2698540533 > > > >Call-ID: 3135130751(a)192.168.1.20 > > > >CSeq: 2 INVITE > > > >Server: Cisco ATA 186 v2.15 ata18x (030401b) > > > >Content-Length: 0 > > > > > > > >B2BUA->SER > > > > > > > >ACK sip:16045215277@demo.portaone.com:5060;transport=udp;user=phone SIP/2.0 > > > >Via: SIP/2.0/UDP 64.180.102.72:5061 > > > >To: <sip:121@64.180.102.72;user=phone>;tag=2698540533 > > > >From: <sip:380442466396@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >Call-ID: 3135130751(a)192.168.1.20 > > > >CSeq: 2 ACK > > > >Max-Forwards: 70 > > > >Content-Length: 0 > > > > > > > >SER->ATA > > > > > > > >ACK sip:16045215277@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@64.180.102.72;user=phone>;tag=2698540533 > > > >From: <sip:380442466396@64.180.102.72:5061;user=phone>;tag=4505a91c4165b3ffb1b4df0ff79c2904 > > > >Call-ID: 3135130751(a)192.168.1.20 > > > >CSeq: 2 ACK > > > >Max-Forwards: 69 > > > >Content-Length: 0 > > > > > > > >[the last 3 repeat until timeout hits] > > > >_______________________________________________ > > > >Serusers mailing list > > > &gt;serusers(a)lists.iptel.org > > > >http://lists.iptel.org/mailman/listinfo/serusers > > > > > > -- > > > Jiri Kuthan http://iptel.org/~jiri/ > > _______________________________________________ > > Serusers mailing list > > serusers(a)lists.iptel.org > > http://lists.iptel.org/mailman/listinfo/serusers > _______________________________________________ > Serusers mailing list > serusers(a)lists.iptel.org > http://lists.iptel.org/mailman/listinfo/serusers

Not only that, but there is also a bug which causes match failure due to extra space in the ACK,

Please disregard this one - I've checked the code in question and it does exactly what I need, namely compares URI in ACK with URI in original INVITE before it was rewritten. Matching failures were probably due to two bugs that I've described in the next two messages following this one. I have a patch for both of them and will submit it after testing. -Maxim On Tue, Apr 08, 2003 at 05:56:17PM +0300, Maxim Sobolev wrote: _______________________________________________ Serusers mailing list serusers(a)lists.iptel.org http://lists.iptel.org/mailman/listinfo/serusers