[SR-Users] how to catch attacker using bad request line?

Mon Sep 17 16:20:19 CEST 2018

I guess you have some modules that registered to process non-sip
traffic, such as xhttp, xmlrpc, ... the parse_msg() throws error and in
such case the processing is delegated to non-sip message handling, if
all skipped, then ended up on trying going further as sip ...

I just pushed a patch to deal with it properly. Can you test? if all ok,
feel free to backport.

Cheers,
Daniel

On 17.09.18 15:59, Juha Heinanen wrote:
> Daniel-Constantin Mierla writes:
>
>> Can you send all log messages with debug=3?
> Below.
>
>> Btw, the source ip variable is $si.
> Oh yes, I had just copied the statement from other part of config,
> where $si has been assigned to $var(src_ip).
>
> -- Juha
>
> Sep 17 16:56:07 char /usr/bin/sip-proxy[24183]: INFO: <core> [core/cfg/cfg_ctx.c:595]: cfg_set_now(): core.debug has been changed to 3
> sip-proxy_ctl> Sep 17 16:56:16 char /usr/bin/sip-proxy[24255]: DEBUG: <core> [core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection: 192.168.43.107
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24255]: DEBUG: <core> [core/tcp_main.c:999]: tcpconn_new(): on port 48636, type 2
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24255]: DEBUG: <core> [core/tcp_main.c:1305]: tcpconn_add(): hashes: 1768:3207:3940, 1
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24255]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0x55839aa16da0, 67, 2, 0x7fb01cc67930), fd_no=55
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24255]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0x55839aa16da0, 67, -1, 0x0) fd_no=56 called
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24255]: DEBUG: <core> [core/tcp_main.c:4196]: handle_tcpconn_ev(): sending to child, events 1
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24255]: DEBUG: <core> [core/tcp_main.c:3847]: send2child(): checking per-socket generic workers (24205/27..24230/34) [tcp:192.168.43.107:5060]
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24255]: DEBUG: <core> [core/tcp_main.c:3875]: send2child(): selected tcp worker 0 27(24205) for activity on [tcp:192.168.43.107:5060], 0x7fb01cc67930
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/tcp_read.c:1759]: handle_io(): received n=8 con=0x7fb01cc67930, fd=12
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line(): parse_first_line: bad request first line
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:251]: parse_first_line(): at line 0 char 35:
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:257]: parse_first_line(): parsed so far: REGISTERsip:test.tutpro.com SIP/2.0
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:262]: parse_first_line(): parse_first_line: bad message (offset: 35)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/tcp_read.c:1560]: tcp_read_req(): content-length=0
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line(): parse_first_line: bad request first line
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:251]: parse_first_line(): at line 0 char 35:
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:257]: parse_first_line(): parsed so far: REGISTERsip:test.tutpro.com SIP/2.0
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:262]: parse_first_line(): parse_first_line: bad message (offset: 35)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): invalid message
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/msg_parser.c:681]: parse_msg(): ERROR: parse_msg: message=<REGISTERsip:test.tutpro.com SIP/2.0#015#012Via: SIP/2.0/TCP 192.168.43.107:40797;branch=z9hG4bK7a6e707b367651ed;rport#015#012Contact: <sip:test-0x560c9b9d4790 at 192.168.43.107:40797;transport=tcp>;expires=600;+sip.instance="<urn:uuid:9b21c1a8-dc58-a3d6-83d5-7be67cbe70ce>";q=0.5;reg-id=1#015#012Max-Forwards: 70#015#012Route: <sip:192.168.43.107:5060;transport=tcp;lr>#015#012To: <sip:test at test.tutpro.com>#015#012From: <sip:test at test.tutpro.com>;tag=ab41d0eaaf619e81#015#012Call-ID: 08f94737eec75885#015#012CSeq: 26277 REGISTER#015#012User-Agent: baresip v0.5.11 (x86_64/linux)#015#012Supported: gruu, outbound, path#015#012Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,NOTIFY,SUBSCRIBE,INFO,MESSAGE#015#012Content-Length: 0#015#012#015#012>
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/msg_parser.c:83]: get_hdr_field(): null buffer pointer
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/msg_parser.c:279]: get_hdr_field(): error exit
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: ERROR: <core> [core/parser/msg_parser.c:337]: parse_headers(): bad header field [(null)]
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: WARNING: <core> [core/receive.c:230]: receive_msg(): parsing relevant headers failed
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/receive.c:232]: receive_msg(): --- received sip message - reply - call-id: [] - cseq: []
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/receive.c:449]: receive_msg(): cleaning up
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line(): parse_first_line: bad request first line
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:251]: parse_first_line(): at line 0 char 35:
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:257]: parse_first_line(): parsed so far: REGISTERsip:test.tutpro.com SIP/2.0
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:262]: parse_first_line(): parse_first_line: bad message (offset: 35)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/tcp_read.c:1560]: tcp_read_req(): content-length=0
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line(): parse_first_line: bad request first line
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:251]: parse_first_line(): at line 0 char 35:
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:257]: parse_first_line(): parsed so far: REGISTERsip:test.tutpro.com SIP/2.0
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/parse_fline.c:262]: parse_first_line(): parse_first_line: bad message (offset: 35)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): invalid message
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/msg_parser.c:681]: parse_msg(): ERROR: parse_msg: message=<REGISTERsip:test.tutpro.com SIP/2.0#015#012Via: SIP/2.0/TCP 192.168.43.107:40797;branch=z9hG4bKf685c1d98f625150;rport#015#012Contact: <sip:foo-0x560c9b9d88d0 at 192.168.43.107:40797;transport=tcp>;expires=600;+sip.instance="<urn:uuid:9b21c1a8-dc58-a3d6-83d5-7be67cbe70ce>";q=0.5;reg-id=1#015#012Max-Forwards: 70#015#012Route: <sip:192.168.43.107:5060;transport=tcp;lr>#015#012To: <sip:foo at test.tutpro.com>#015#012From: <sip:foo at test.tutpro.com>;tag=4728ad9cfe4fd2bd#015#012Call-ID: abee5e4caabe3878#015#012CSeq: 17544 REGISTER#015#012User-Agent: baresip v0.5.11 (x86_64/linux)#015#012Supported: gruu, outbound, path#015#012Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,NOTIFY,SUBSCRIBE,INFO,MESSAGE,REFER#015#012Content-Length: 0#015#012#015#012>
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/msg_parser.c:83]: get_hdr_field(): null buffer pointer
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/parser/msg_parser.c:279]: get_hdr_field(): error exit
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: ERROR: <core> [core/parser/msg_parser.c:337]: parse_headers(): bad header field [(null)]
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: WARNING: <core> [core/receive.c:230]: receive_msg(): parsing relevant headers failed
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/receive.c:232]: receive_msg(): --- received sip message - reply - call-id: [] - cseq: []
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/xavp.c:495]: xavp_destroy_list(): destroying xavp list (nil)
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/receive.c:449]: receive_msg(): cleaning up
> Sep 17 16:56:16 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0x55839aa5ff40, 12, 2, 0x7fb01cc67930), fd_no=1
>
> sip-proxy_ctl> cfg.set core debug Sep 17 16:56:22 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0x55839aa5ff40, 12, -1, 0x10) fd_no=2 called
> Sep 17 16:56:22 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/tcp_read.c:1680]: release_tcpconn(): releasing con 0x7fb01cc67930, state 1, fd=12, id=1 ([192.168.43.107]:48636 -> [192.168.43.107]:5060)
> Sep 17 16:56:22 char /usr/bin/sip-proxy[24205]: DEBUG: <core> [core/tcp_read.c:1684]: release_tcpconn(): extra_data (nil)
> Sep 17 16:56:22 char /usr/bin/sip-proxy[24255]: DEBUG: <core> [core/tcp_main.c:3307]: handle_tcp_child(): reader response= 7fb01cc67930, 1 from 0
> Sep 17 16:56:22 char /usr/bin/sip-proxy[24255]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0x55839aa16da0, 67, 2, 0x7fb01cc67930), fd_no=55
> Sep 17 16:56:22 char /usr/bin/sip-proxy[24255]: DEBUG: <core> [core/tcp_main.c:3434]: handle_tcp_child(): CONN_RELEASE  0x7fb01cc67930 refcnt= 1
> 1

-- 
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Kamailio World Conference -- www.kamailioworld.com
Kamailio Advanced Training, Nov 12-14, 2018, in Berlin -- www.asipto.com