Hello,

if you look at network trace on port 5060 for Kamailio, what packets do you see being received? Be sure you wantch all sockets kamailio is listening on (including loopback interface, if it is the case).

Cheers,
Daniel

On 05/01/16 09:33, Sergey Basov wrote:
Hi, All.

I have a strange issue occuring, when I enable the siptrace
functionality within the routing logic, I begin to get a lot of
parser error as show below. Is this normal behavior?

This errors appears only when topoh module is enabled...

As I see with wireshark, there is no duplicates or returned HEP packets...


I enable siptrace as follows:

request_route {
   sip_trace();
   setflag(22);
    ...
}

Configuration of the topoh and siptrace modules:
# ----- topoh params -----
modparam("topoh", "mask_key", "123456789")
modparam("topoh", "mask_ip", "127.0.0.8")

#Siptrace
modparam("siptrace", "duplicate_uri", "sip:10.1.23.20:9060")
modparam("siptrace", "hep_mode_on", 1)
modparam("siptrace", "hep_version", 2)
modparam("siptrace", "trace_to_database", 0)
modparam("siptrace", "trace_flag", 22)
modparam("siptrace", "trace_on", 1)
modparam("siptrace", "force_send_sock", "sip:10.1.23.23:5060")
modparam("siptrace", "traced_user_avp", "$avp(s:user)")

output from kamailio.log with debug enabled:

Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: topoh [th_msg.c:180]: th_mask_via(): body: 120: [SIP/2.0/UDP 10.10.206.39:5060;received=10.10.206.39;TH=dcv;branch=z9hG4bK-d8754z-2e9df22b7c5cb6c9-1---d8754z-;rport=5060]
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: topoh [th_msg.c:191]: th_mask_via(): +body: 199: [SIP/2.0/UDP 127.0.0.8;branch=z9hG4bKsr-s7wTDLa0zUfYZXl5zpl0zpl0z.lRD.zok.sEG.lvBJY.euwReuTfzpl0zpl0z.lRD.zokqZaxuZ.P.c3BJX01R5fO.wCZLZ3WSqMkhBqGgCczJsoeV1SzJa21LY.1.e.kW7jDW7ceh52GpZKDpcSBVfSPh7qzh1E]
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: topoh [th_msg.c:322]: th_mask_record_route(): no record route header
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7fcfacccb7a8, callback type 4194304, id 0 entered
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: siptrace [siptrace.c:766]: sip_trace_store_db(): database connection not initialized
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: siptrace [siptrace.c:1875]: pipport2su(): the port string is 5060
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: siptrace [siptrace.c:1875]: pipport2su(): the port string is 5060
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: <core> [proxy.c:265]: mk_proxy(): doing DNS lookup...
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: <core> [resolve.c:1208]: srv_sip_resolvehost(): 10.1.23.20:9060 proto=1
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: <core> [resolve.c:1329]: srv_sip_resolvehost(): returning 0x9da020 (10.1.23.20:9060 proto=1)
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: siptrace [siptrace.c:1687]: trace_send_hep_duplicate(): setting up the socket_info
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: siptrace [siptrace.c:1694]: trace_send_hep_duplicate(): force_send_sock activated, grep for the sock_info
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: <core> [socket_info.c:563]: grep_sock_info(): checking if host==us: 10==11 && [10.1.23.23] == [10.56.41.23]
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: <core> [socket_info.c:566]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: <core> [socket_info.c:563]: grep_sock_info(): checking if host==us: 10==11 && [10.1.23.23] == [10.56.42.23]
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: <core> [socket_info.c:566]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: <core> [socket_info.c:563]: grep_sock_info(): checking if host==us: 10==10 && [10.1.23.23] == [10.1.23.23]
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: <core> [socket_info.c:566]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: siptrace [siptrace.c:1701]: trace_send_hep_duplicate(): found socket while grep: [10.1.23.23] [10.1.23.23]
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: INFO: <core> [parser/parse_fline.c:144]: parse_first_line(): ERROR:parse_first_line: method not followed by SP
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: ERROR: <core> [parser/parse_fline.c:257]: parse_first_line(): parse_first_line: bad message (offset: 0)
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: <core> [parser/msg_parser.c:602]: parse_msg(): parse_msg: invalid message
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: ERROR: <core> [parser/msg_parser.c:688]: parse_msg(): ERROR: parse_msg: message=<#002#020#002#021#023�#023�#0128*#027#0128*#024zx�V�#016#003>
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: topoh [topoh_mod.c:214]: th_prepare_msg(): outbuf buffer parsing failed!
Jan  5 10:02:02 sip1 /usr/sbin/kamailio[28348]: DEBUG: tm [t_funcs.c:362]: t_relay_to(): SER: new transaction fwd'ed




Is there any way I can disable seeing these messages? What are these messages?

Any thoughts are appreciated.

Thanks in advance.

--
Best regards,
Sergey Basov                     e-mail: sergey.v.basov@gmail.com


_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users

-- 
Daniel-Constantin Mierla
http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Book: SIP Routing With Kamailio - http://www.asipto.com
http://miconda.eu