[SR-Users] sanity from uri check

Tue Mar 15 14:18:58 CET 2022

Strange! The next log message indicates that it gets to From URI check:

Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: sanity [sanity.c:776]: check_parse_uris(): looking up From header

But for what so ever reason is not triggering a failure, it needs to dig
in ...

Daniel

On 15.03.22 14:07, Juha Heinanen wrote:
> Daniel-Constantin Mierla writes:
>
>> Can you double check that latest version is used for testing?
> It is the latest version.
>
>> You can also run with debug=3 and provide the logs printed by core and
>> sanity module.
> The log is below.  Could it be that uri_checks value 3 are not correct,
> i.e., that there is a bug in README?
>
> I'm just wondering, since the log does not have line:
>
> get_hdr_field(): <From>
>
> -- Juha
>
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043887]: DEBUG: <core> [core/ip_addr.c:571]: print_ip(): tcpconn_new: new tcp connection: 192.168.255.95
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043887]: DEBUG: <core> [core/tcp_main.c:1216]: tcpconn_new(): on port 37775, type 2, socket 59
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043887]: DEBUG: <core> [core/tcp_main.c:1548]: tcpconn_add(): hashes: 2713:680:331, 9
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043887]: DEBUG: <core> [core/io_wait.h:374]: io_watch_add(): processing io_watch_add(0x561ddaad2bc0, 59, 2, 0x7f5239bc16a0) - fd_no=52
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043887]: DEBUG: <core> [core/io_wait.h:599]: io_watch_del(): DBG: io_watch_del (0x561ddaad2bc0, 59, -1, 0x0) fd_no=53 called
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043887]: DEBUG: <core> [core/tcp_main.c:4545]: handle_tcpconn_ev(): sending to child, events 1
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043887]: DEBUG: <core> [core/tcp_main.c:4187]: send2child(): checking per-socket generic workers (3043875/20..3043882/27) [tcp:192.168.255.95:5060]
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043887]: DEBUG: <core> [core/tcp_main.c:4215]: send2child(): selected tcp worker idx:0 proc:20 pid:3043875 for activity on [tcp:192.168.255.95:5060], 0x7f5239bc16a0
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/tcp_read.c:1735]: handle_io(): received n=8 con=0x7f5239bc16a0, fd=11
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line(): first line type 1 (request) flags 1
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/tcp_read.c:1533]: tcp_read_req(): content-length=0
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/receive.c:136]: sip_check_fline(): first line indicates a SIP request
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line(): first line type 1 (request) flags 1
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/msg_parser.c:677]: parse_msg(): SIP Request:
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/msg_parser.c:678]: parse_msg():  method:  <OPTIONS>
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/msg_parser.c:680]: parse_msg():  uri:     <sip:test at test.tutpro.com>
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/msg_parser.c:682]: parse_msg():  version: <SIP/2.0>
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name(): parsed header name [Via] type 1
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/parse_via.c:1300]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-3044756-1-0>; state=16
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/msg_parser.c:555]: parse_headers(): Via found, flags=2
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/msg_parser.c:557]: parse_headers(): this is the first via
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name(): parsed header name [Max-Forwards] type 8
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name(): parsed header name [To] type 3
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/parse_addr_spec.c:884]: parse_addr_spec(): end of header reached, state=10
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): <To> [28]; uri=[sip:test at test.tutpro.com]
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body (28)[<sip:test at test.tutpro.com>#015#012], to tag (0)[]
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name(): parsed header name [From] type 4
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name(): parsed header name [Call-ID] type 6
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name(): parsed header name [CSeq] type 5
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <OPTIONS>
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/receive.c:387]: receive_msg(): --- received sip message - request - call-id: [1-3044756 at 192.168.255.95] - cseq: [1 OPTIONS]
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/receive.c:259]: ksr_evrt_pre_routing(): event route core:pre-routing not defined
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/receive.c:469]: receive_msg(): preparing to run routing scripts...
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: sanity [sanity.c:758]: check_parse_uris(): check_parse_uris entered
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: sanity [sanity.c:762]: check_parse_uris(): parsing ruri
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: sanity [sanity.c:776]: check_parse_uris(): looking up From header
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=1
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: <core> [core/parser/parse_addr_spec.c:884]: parse_addr_spec(): end of header reached, state=29
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: sanity [sanity.c:837]: check_parse_uris(): check_parse_uris passed
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: DEBUG: sanity [sanity_mod.c:254]: w_sanity_check(): sanity checks result: 1
> Mar 15 14:58:42 /usr/bin/sip-proxy[3043875]: INFO: OPTIONS <sip:test at test.tutpro.com> from <sip:@192.168.255.95:5062> is OK

-- 
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Kamailio Advanced Training - Online
  March 28-31, 2022 (Europe Timezone)
  * https://www.asipto.com/sw/kamailio-advanced-training-online/