[SR-Users] TCP message parsing & connection close issue

[Alex Balashov]

I've also got a binary capture and would be happy to provide privately.

On 08/05/2016 06:24 PM, Alex Balashov wrote:

> Hello,
>
> I've got an odd issue where:
>
> 1. TCP client makes call out through Kamailio.
>
> 2. Call is answered, TCP client sends e2e ACK.
>
> 3. Parser chokes on ACK, closes TCP connection (SYN+FIN).
>
> 4. Subsequent messages from the client, immediately following the ACK
> (about 240 ms later), come through because the client is halfway around
> the world - about 250 ms away - and is not yet aware the connection has
> been closed. Otherwise, it would presumably try to re-establish the
> connection before sending anything.
>
> Anyway, messages from the parser concerning the ACK are:
>
> ---
> Aug  4 21:55:57 sip-proxy /usr/local/kamailio/sbin/kamailio[14680]:
> INFO: <core> [parser/parse_fline.c:144]: parse_first_line():
> ERROR:parse_first_line: method not followed by SP
>
> Aug  4 21:55:57 sip-proxy /usr/local/kamailio/sbin/kamailio[14680]:
> ERROR: <core> [parser/parse_fline.c:257]: parse_first_line():
> parse_first_line: bad message (offset: 0)
>
> Aug  4 21:55:57 sip-proxy /usr/local/kamailio/sbin/kamailio[14680]:
> ERROR: <core> [parser/msg_parser.c:690]: parse_msg(): ERROR: parse_msg:
> message=<0#015#012a=rtcp:4007 IN IP4
> 1.1.1.1:1071#015#012a=sendrecv#015#012a=rtpmap:0
> PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:96
> telephone-event/8000#015#012a=fmtp:96 0-16#015#012ACK
> sip:*98*0b3ff883-a89d-4317-b758-8979682f5357 at 10.0.2.53:5060;transport=udp SIP/2.0#015#012Via:
> SIP/2.0/TCP
> 1.1.1.1:61979;branch=z9hG4bKPjc15bf9fdded940cab7f859634b9f036e;alias#015#012Max-Forwards:
> 70#015#012From:
> sip:4b57be8d-267d-48c4-aa82-0f3a269d74cb at sip.evaristesys.com;tag=dd1d7fd0344d47b7b22c4017091df17a#015#012To:
> sip:*98*0b3ff883-a89d-4317-b758-8979682f5357 at sip.evaristesys.com;tag=2rZDKcBFmU65S#015#012Call-ID:
> 5ba5a84451074159aaaa931eb1f98fe5#015#012CSeq: 3071 ACK#015#012Route:
> <sip:2.2.2.2;transport=tcp;lr;r2=on;ftag=dd1d7fd0344d47b7b22c4017091df17a;rtp_set_id=1>#015#012Route:
> <sip:10.0.2.119;lr;r2=on;ftag=dd1d7fd0344d47b7b22c4017091df17a;rtp_set_id=1>#015#012Content-Length:
>  0#015#012#015#012>
> Aug  4 21:55:57 sip-proxy /usr/local/kamailio/sbin/kamailio[14680]:
> ERROR: <core> [receive.c:173]: receive_msg(): core parsing of SIP
> message failed (1.1.1.1:61979/2)
> ---
>
> That doesn't look like a clean message buffer to me. The message should
> start here:
>
> ACK
> sip:*98*0b3ff883-a89d-4317-b758-8979682f5357 at 10.0.2.53:5060;transport=udp SIP/2.0#015#012Via:
> SIP/2.0/TCP ...
>
> But instead it's got these SDP attributes prepended:
>
> 0#015#012a=rtcp:4007 IN IP4
> 1.1.1.1:1071#015#012a=sendrecv#015#012a=rtpmap:0
> PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:96
> telephone-event/8000#015#012a=fmtp:96 0-16#015#012
>
> These SDP attribute appear to have fallen off the back of the SDP offer
> in the initial INVITE:
>
> v=0
> o=- 3679365582 3679365582 IN IP4 10.0.0.200
> s=pjmedia
> t=0 0
> m=audio 4006 RTP/AVP 0 8 96
> c=IN IP4 1.1.1.1
>
> The relationship between the 4006 RTP port and the 4007 RTCP port
> suggests that these two things belong together.
>
> This is on kamailio 4.4.0 (x86_64/linux) d4f23c. Any help would be
> greatly appreciated! The issue is consistently reproducible and this
> happens every time.
>
> Cheers,
>
> -- Alex
>


-- 
Alex Balashov | Principal | Evariste Systems LLC
1447 Peachtree Street NE, Suite 700
Atlanta, GA 30309
United States

Tel: +1-800-250-5920 (toll-free) / +1-678-954-0671 (direct)
Web: http://www.evaristesys.com/, http://www.csrpswitch.com/