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@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@test.tutpro.com>#015#012From:
<sip:test@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@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@test.tutpro.com>#015#012From:
<sip:foo@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