[sr-dev] [kamailio/kamailio] 200 OK & ACK & topoh issues (#1541)

Tue May 22 20:10:18 CEST 2018

### Description

A certain inbound provider does not return ACK R-URI as an exact copy of contact. A parameter is appended to it, like below:

200 OK Contact:

`Contact: <sip:35.197.205.XXX:5060;line=sr-N6IAzJd4WxFLWxVlz.jwWB0yM.y7MlV7zGZlMlvuMx3A>`

ACK R-URI:

`ACK sip:35.197.205.XXX:5060;line=sr-N6IAzJd4WxFLWxVlz.jwWB0yM.y7MlV7zGZlMlvuMx3A;user=phone SIP/2.0`

As you can see, the `user=phone` is appended along with `line=` put by topoh.

### Troubleshooting

#### Reproduction

I am not sure how this can be reproductible. I've put the URI with and without `user=phone` part in a small C app that calls kamailio's `parse_params` function and both resolved to one and two params, as expected, so the problem must come from `parse_uri`.
See the debug logs below that show the difference between a "good" ACK and a "bad" ACK. `topoh` doesn't get its `line=` param, so it doesn't perform the `Contact` header rewrite. The ACK does not match a dialog/transaction and it is forwarded to itself (from internal IP to external IP, this being a kamailio behind NAT, but that's not the problem).

#### Debugging Data

#### Log Messages

This is the "good" call, with ACK R-URI identical to Contact header. See the "+decoded" line:

```
13(40) DEBUG: topoh [topoh_mod.c:249]: th_prepare_msg(): no second via in this message
13(40) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=as496aacd0
13(40) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
13(40) DEBUG: topoh [th_msg.c:1165]: th_route_direction(): ftag match
13(40) DEBUG: topoh [th_msg.c:763]: th_unmask_ruri(): +decoded: 34: [sip:+441274957XXX at 10.32.2.133:5060]
13(40) DEBUG: topoh [topoh_mod.c:358]: th_msg_received(): adding cookie: dc
13(40) DEBUG: topoh [th_msg.c:997]: th_add_hdr_cookie(): added cookie header [TH: dch
```

This is the "bad" call, with ACK R-URI having a `user=phone` param appended to original Contact contents:

```
10(37) DEBUG: topoh [topoh_mod.c:249]: th_prepare_msg(): no second via in this message
10(37) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=3735986184-753647
10(37) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
10(37) DEBUG: topoh [th_msg.c:1165]: th_route_direction(): ftag match
10(37) DEBUG: <core> [core/parser/parse_param.c:580]: parse_params2(): empty uri params, skipping
10(37) DEBUG: topoh [topoh_mod.c:358]: th_msg_received(): adding cookie: dc
10(37) DEBUG: topoh [th_msg.c:997]: th_add_hdr_cookie(): added cookie header [TH: dch
```

#### SIP Traffic

```
U 2018/05/21 10:22:53.206320 35.197.205.XXX:5060 -> 88.215.58.YYY:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP 88.215.58.YYY:5060;rport=5060;branch=z9hG4bK469d20c71c138e366475cd537dc0c68b.
Record-Route: <sip:35.197.205.XXX;lr;ftag=3735908572-610467;vsf=AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA7dXNlcj1waG9uZQ--;vst=AAAAAAAAAAAAAAAAAAAAAAAACQgAAQMbFhsLHTE1OjUwNjA7dXNlcj1waG9uZQ--;did=f17.b7f>.
From: <sip:+16098378XXX at 88.215.58.YYY;user=phone>;tag=3735908572-610467.
To: <sip:+441242395XXX at 88.215.58.YYY:5060;user=phone>;tag=as3147fc45.
Call-ID: 5577511-3735908572-610459 at MSX163.XXX.com.
CSeq: 1 INVITE.
Server: Asterisk PBX 1.8.28-cert5.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE.
Supported: replaces.
Contact: <sip:35.197.205.XXX:5060;line=sr-N6IAzJd4WxFLWxVlz.jwWB0yM.y7MlV7zGZlMlvuMx3A>.
Content-Type: application/sdp.
Content-Length: 259.
.
v=0.
o=root 1611167628 1611167628 IN IP4 35.197.206.251.
s=Asterisk PBX 1.8.28-cert5.
c=IN IP4 35.197.206.251.
t=0 0.
m=audio 10948 RTP/AVP 8 101.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.
a=sendrecv.
a=rtcp:10949.

U 2018/05/21 10:22:53.206827 88.215.58.YYY:5060 -> 35.197.205.XXX:5060
ACK sip:35.197.205.XXX:5060;line=sr-N6IAzJd4WxFLWxVlz.jwWB0yM.y7MlV7zGZlMlvuMx3A;user=phone SIP/2.0.
Max-Forwards: 68.
Route: <sip:35.197.205.XXX;lr;ftag=3735908572-610467;vsf=AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA7dXNlcj1waG9uZQ--;vst=AAAAAAAAAAAAAAAAAAAAAAAACQgAAQMbFhsLHTE1OjUwNjA7dXNlcj1waG9uZQ--;did=f17.b7f>.
To: <sip:+441242395XXX at 88.215.58.YYY:5060;user=phone>;tag=as3147fc45.
From: <sip:+16098378XXX at 88.215.58.YYY;user=phone>;tag=3735908572-610467.
Call-ID: 5577511-3735908572-610459 at MSX163.XXX.com.
CSeq: 1 ACK.
Allow: PUBLISH,MESSAGE,UPDATE,SUBSCRIBE,REFER,INFO,NOTIFY,OPTIONS,BYE,INVITE,ACK,CANCEL.
Via: SIP/2.0/UDP 88.215.58.15:5060;branch=z9hG4bK6c862e8111736dc6d7d22479393d1f2d.
Contact: <sip:+16098378YYY at 88.215.58.YYY:5060>.
Content-Length: 0.

```

### Possible Solutions

Changed the provider to avoid downtime, but the `empty uri params, skipping` error from `parse_params2` is strange, considering that we do not have a single param but 2.

### Additional Information

  * **Kamailio Version** - output of `kamailio -v`

```
version: kamailio 5.0.4 (x86_64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
compiled with gcc 5.4.0
```

* **Operating System**:

```
Linux gke-lon-1-sbc-in-082a7447-9rll 4.13.0-1011-gcp #15-Ubuntu SMP Mon Feb 12 16:29:04 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
```

-- 
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1541
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-dev/attachments/20180522/d5fa72e3/attachment-0001.html>