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@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@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@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@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@test.tutpro.com from sip:@192.168.255.95:5062 is OK