siptrace: sip_trace_mode("d") not working/segfaults

[btriller]

Description

1. Using function sip_trace_mode() with parameter d to enable dialog tracing mode logs:

BUG: siptrace [siptrace.c:1671]: add_info_xavp(): URI should be in raw format here
ERROR: siptrace [siptrace.c:888]: sip_trace_helper(): failed to serialize siptrace info! Won't trace dialog!

2. If trace_flag is set and sip_trace_mode("d") is used before one of the parameterized variants of sip_trace() Kamailio segfaults.

Troubleshooting

Reproduction

module parameters:

#!define FLT_SIPTRACE 5
modparam("siptrace", "trace_mode", 0)
modparam("siptrace", "trace_flag", FLT_SIPTRACE)
modparam("siptrace", "trace_on", 1)
modparam("siptrace", "trace_to_database", 0)
modparam("siptrace", "hep_mode_on", 1)
modparam("siptrace", "hep_version", 3)
modparam("siptrace", "hep_capture_id", 1234)

request_route {
...
  if (is_method("INVITE")) {
    sip_trace_mode("d");
  }
}

request_route {
...
  if (is_method("INVITE")) {
    setflag(FLT_SIPTRACE);
    sip_trace_mode("d");
    sip_trace("sip:1.2.3.4:9060");
  }
}

Debugging Data

(gdb) bt
#0  0x00007f498ffddeaf in memcpy () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007f495ffb5369 in sip_trace_helper (msg=0x7f498c1703b8, dst=0x7fff45477ab0, duri=0x7fff45477a50, corid=0x0, dir=0x0, trace_type=SIPTRACE_TRANSACTION) at siptrace.c:871
#2  0x00007f495ffb7729 in w_sip_trace3 (msg=0x7f498c1703b8, dest=0x7f498c0863a8 "\210S\t\214I\177", correlation_id=0x0, trace_type_p=0x0) at siptrace.c:1041
#3  0x00007f495ffb6774 in w_sip_trace1 (msg=0x7f498c1703b8, dest=0x7f498c0863a8 "\210S\t\214I\177", p2=0x0) at siptrace.c:978
#4  0x00005603f0600ea1 in do_action (h=0x7fff45479270, a=0x7f498c0949a0, msg=0x7f498c1703b8) at core/action.c:1079
#5  0x00005603f060f4bd in run_actions (h=0x7fff45479270, a=0x7f498c093ca8, msg=0x7f498c1703b8) at core/action.c:1578
#6  0x00005603f0600d85 in do_action (h=0x7fff45479270, a=0x7f498c0a3758, msg=0x7f498c1703b8) at core/action.c:1064
#7  0x00005603f060f4bd in run_actions (h=0x7fff45479270, a=0x7f498c08f758, msg=0x7f498c1703b8) at core/action.c:1578
#8  0x00005603f060b397 in do_action (h=0x7fff45479270, a=0x7f498c0a3f68, msg=0x7f498c1703b8) at core/action.c:1248
#9  0x00005603f060f4bd in run_actions (h=0x7fff45479270, a=0x7f498c019500, msg=0x7f498c1703b8) at core/action.c:1578
#10 0x00005603f060fd0b in run_top_route (a=0x7f498c019500, msg=0x7f498c1703b8, c=0x0) at core/action.c:1663
...
(gdb) frame 1
#1  0x00007f495ffb5369 in sip_trace_helper (msg=0x7f498c1703b8, dst=0x7fff45477ab0, duri=0x7fff45477a50, corid=0x0, dir=0x0, trace_type=SIPTRACE_TRANSACTION) at siptrace.c:871
871                             memcpy(info->u.dup_uri.s, duri->s, duri->len);
(gdb) info locals
alloc_size = 88
info = 0x7f4967941fe0
__func__ = "sip_trace_helper"
(gdb) p *info
$1 = {correlation_id = {s = 0x0, len = 0}, u = {dup_uri = {s = 0x0, len = 0}, dest_info = {send_sock = 0x0, to = {s = {sa_family = 0, sa_data = '\000' <repeats 13 times>}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0},
          sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}},
      id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 0 '\000', proto_pad0 = 0 '\000', proto_pad1 = 0}}, uriState = STRACE_RAW_URI}
(gdb) p *dst
$2 = {send_sock = 0x0, to = {s = {sa_family = 2, sa_data = "#d\001\002\003\004\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 25635, sin_addr = {s_addr = 67305985}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2,
      sin6_port = 25635, sin6_flowinfo = 67305985, sin6_addr = {__in6_u = {__u6_addr8 = '\000' <repeats 15 times>, __u6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id = 0}}, id = 0, send_flags = {f = 0, blst_imask = 0}, proto = 1 '\001',
  proto_pad0 = 0 '\000', proto_pad1 = 0}

Additional Information

• Kamailio Version - output of kamailio -v

% kamailio -v
version: kamailio 5.4.0-dev3 (x86_64/linux)
flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED
ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
compiled with gcc 6.3.0

[miconda]

Can you also get the gdb output for:

frame 1
p *duri

[miconda]

Forget my previous comment, I think I found the reason, a fix being pushed with the commit referenced above. Can you test the patch and report if all ok now.

[miconda]

It was backported to 5.3 branch.