[Serusers] Troubles matching 487's to subsequent ACKs

[Maxim Sobolev]

Hi,

We have recently switched to 0.8.11 for our production server and
I have noticed that ser no longer can match 487 Request cancelled
reply to subsequent ACK, at least in the cases when ATA186 with
latest firmware 2.16 is used as the originating UA. I wonder
who is responsible for this: ATA or SER. The only strange thing
that I see in the log is that ATA includes the following extra
parameters into the first Via hf: rport=5060;received=195.234.212.178.

ATA->SER

INVITE sip:380445732729 at 64.180.102.72;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.0.253:5060
From: <sip:380442466396 at 64.180.102.72;user=phone>;tag=4197094684
To: <sip:380445732729 at 64.180.102.72;user=phone>
Call-ID: 2777157492 at 192.168.0.253
CSeq: 2 INVITE
Contact: <sip:380442466396 at 192.168.0.253:5060;user=phone;transport=udp>
User-Agent: Cisco ATA 186  v2.16 ata18x (030509a)
Authorization: Digest username="380442466396",realm="64.180.102.72",nonce="3f168
ef30be264b823354f5b14bef51f8c3636de",uri="sip:380445732729 at 64.180.102.72",respon
se="d5a544d0eb3103e9f67b4e2af839054d"
Expires: 300
Content-Length: 257
Content-Type: application/sdp
o=380442466396 40288 40288 IN IP4 192.168.0.253
s=ATA186 Call
c=IN IP4 192.168.0.253
t=0 0
m=audio 13000 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

SER->ATA

SIP/2.0 100 trying -- your call is important to us
Via: SIP/2.0/UDP 192.168.0.253:5060;rport=5060;received=195.234.212.178
From: <sip:380442466396 at 64.180.102.72;user=phone>;tag=4197094684
To: <sip:380445732729 at 64.180.102.72;user=phone>
Call-ID: 2777157492 at 192.168.0.253
CSeq: 2 INVITE
Server: Sip EXpress router (0.8.11rc1 (i386/freebsd))
Content-Length: 0

SER->ATA

SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 192.168.0.253:5060;rport=5060;received=195.234.212.178
To: <sip:380445732729 at 64.180.102.72;user=phone>;tag=d429e01d
From: <sip:380442466396 at 64.180.102.72;user=phone>;tag=4197094684
Call-ID: 2777157492 at 192.168.0.253
CSeq: 2 INVITE
Record-Route: <sip:380445732729 at 64.180.102.72;lr>
Content-Type: application/sdp
Content-Length: 283
o=CiscoSystemsSIP-GW-UserAgent 503 692 IN IP4 212.119.160.61
s=SIP Call
c=IN IP4 212.119.160.61
t=0 0
m=audio 17182 RTP/AVP 4 19 101
c=IN IP4 212.119.160.61
a=rtpmap:4 G723/8000
a=rtpmap:19 CN/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:4 annexa=no
a=fmtp:101 0-15

ATA->SER

CANCEL sip:380445732729 at 64.180.102.72;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.0.253:5060
From: <sip:380442466396 at 64.180.102.72;user=phone>;tag=4197094684
To: <sip:380445732729 at 64.180.102.72;user=phone>
Call-ID: 2777157492 at 192.168.0.253
CSeq: 2 CANCEL
User-Agent: Cisco ATA 186  v2.16 ata18x (030509a)
Authorization: Digest username="380442466396",realm="64.180.102.72",nonce="3f168
ef30be264b823354f5b14bef51f8c3636de",uri="sip:380445732729 at 64.180.102.72",respon
se="2953586e366141c5b8062cdfe7678357"
Content-Length: 0

SER->ATA

SIP/2.0 200 cancelling
Via: SIP/2.0/UDP 192.168.0.253:5060;rport=5060;received=195.234.212.178
From: <sip:380442466396 at 64.180.102.72;user=phone>;tag=4197094684
To: <sip:380445732729 at 64.180.102.72;user=phone>;tag=7fe8c93a8cb9c58b2cde45b60b0e
5d5c-7fd1
Call-ID: 2777157492 at 192.168.0.253
CSeq: 2 CANCEL
Server: Sip EXpress router (0.8.11rc1 (i386/freebsd))
Content-Length: 0


SER->ATA

SIP/2.0 487 Request cancelled
Via: SIP/2.0/UDP 192.168.0.253:5060;rport=5060;received=195.234.212.178
From: <sip:380442466396 at 64.180.102.72;user=phone>;tag=4197094684
To: <sip:380445732729 at 64.180.102.72;user=phone>;tag=7fe8c93a8cb9c58b2cde45b60b0e
5d5c-7fd1
Call-ID: 2777157492 at 192.168.0.253
CSeq: 2 INVITE
Server: Sip EXpress router (0.8.11rc1 (i386/freebsd))
Content-Length: 0

ATA->SER

ACK sip:380445732729 at 64.180.102.72;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.0.253:5060;rport=5060;received=195.234.212.178
From: <sip:380442466396 at 64.180.102.72;user=phone>;tag=4197094684
To: <sip:380445732729 at 64.180.102.72;user=phone>;tag=7fe8c93a8cb9c58b2cde45b60b0e
5d5c-7fd1
Call-ID: 2777157492 at 192.168.0.253
CSeq: 2 ACK
User-Agent: Cisco ATA 186  v2.16 ata18x (030509a)
Content-Length: 0

SER->ATA

SIP/2.0 487 Request cancelled
Via: SIP/2.0/UDP 192.168.0.253:5060;rport=5060;received=195.234.212.178
From: <sip:380442466396 at 64.180.102.72;user=phone>;tag=4197094684
To: <sip:380445732729 at 64.180.102.72;user=phone>;tag=7fe8c93a8cb9c58b2cde45b60b0e
5d5c-7fd1
Call-ID: 2777157492 at 192.168.0.253
CSeq: 2 INVITE
Server: Sip EXpress router (0.8.11rc1 (i386/freebsd))
Content-Length: 0

ATA->SER

ACK sip:380445732729 at 64.180.102.72;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.0.253:5060;rport=5060;received=195.234.212.178
From: <sip:380442466396 at 64.180.102.72;user=phone>;tag=4197094684
To: <sip:380445732729 at 64.180.102.72;user=phone>;tag=7fe8c93a8cb9c58b2cde45b60b0e
5d5c-7fd1
Call-ID: 2777157492 at 192.168.0.253
CSeq: 2 ACK
User-Agent: Cisco ATA 186  v2.16 ata18x (030509a)
Content-Length: 0

An so on (487->ACK->487->ACK until timeout hits).

-Maxim