[CRASH] rest_client TLS crash

[bcnewlin]

OpenSIPS version you are running

version: opensips 2.4.6 (x86_64/linux)
flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, QM_MALLOC, DBG_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll, sigio_rt, select.
git revision: aa89b8764
main.c compiled on 00:37:59 Nov 23 2019 with gcc 7

Crash Core Dump

https://pastebin.com/LKt2KRkg

Describe the traffic that generated the bug

Crash is caused when running async REST calls using HTTPS on an OpenSIPS that also has tls_mgm loaded. Crashes were not observed on instances making async REST HTTPS calls without tls_mgm. We plan to test with synchronous REST calls to determine if the asynchronicity (sp?) is related.

To Reproduce

1. Start OpenSIPS with rest_client and tls_mgm loaded.
2. Start traffic that utilizes and async REST call during processing
3. OpenSIPS crashes

Relevant System Logs

Nov 25 14:19:00 [2751] WARNING:core:tcpconn_add_alias: possible port hijack attempt
Nov 25 14:19:00 [2751] WARNING:core:tcpconn_add_alias: alias already present and points to another connection (1488095225 : 5060 and 1488095257 : 5060)
Nov 25 14:19:00 [2751] WARNING:core:do_action: tcp alias failed
Nov 25 14:19:00 [2749] ERROR:rest_client:resume_async_http_req: connected, but transfer timed out (5s)
...
Nov 25 14:19:03 [2736] CRITICAL:core:qm_free: freeing already freed pointer, first free: tls.h: os_free(119) - aborting

OS/environment information

• Operating System: Amazon Linux 2
• OpenSIPS installation: git
• other relevant information:

Additional context

[stale]

Any updates here? No progress has been made in the last 15 days, marking as stale. Will close this issue if no further updates are made in the next 30 days.

[bcnewlin]

After some testing we have found the crashes are only occurring when using the rest client module in async mode.

[stale]

Any updates here? No progress has been made in the last 15 days, marking as stale. Will close this issue if no further updates are made in the next 30 days.

[bogdan-iancu]

Hi Ben,

trying to sort out some things here: have you notice a correlation between TLS and Async usage and the crash? I mean is the crash directly correlated with the TLS or Async usage? Running TLS + sync mode will still result in a crash ?

[bogdan-iancu]

PS: the pastebin for the backtrace expired :(

[bcnewlin]

@bogdan-iancu I will try to get a new backtrace. The crashes seem to require both SIP TLS (tls_mgm) to be loaded and async rest calls to be used.

[bcnewlin]

Here is a new backtrace and version info.

version: opensips 2.4.6 (x86_64/linux)
flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll, sigio_rt, select.
git revision: aa89b8764
main.c compiled on 23:51:06 Jan  7 2020 with gcc 7

core.15464.11.1578509044.txt

[bogdan-iancu]

@bcnewlin , the backtrace shows a crash in the memory manage, indicating, most probably, some memory corruption.
First, from the current core file, could you print:

f 4
p rb
p *rb
p rb->buffer

Also, could you better recompile with the QM_MALLOC + DBG_MALLOC flags (instead of F_MALLOC) ? this will tremendously help in confirming / detecting the memory corruption.

[bcnewlin]

Here is the output of those commands from this core dump:

(gdb) f 4
#4  0x00007fb40b14dd3e in _reply_light (trans=trans@entry=0x7fb41631d450,
    buf=0x7fb45075c378 "SIP/2.0 500 Server Internal Error\r\nTo:  <sip:12287281025@testacdload25.byoc.inintca.com:5061>;tag=8098-42b6033d2d1536267262c7e217474bf8\r\nFrom:  <sip:+994984065678@testacdload25.byoc.inintca.com:5061>;"..., len=431, code=code@entry=500, lock=lock@entry=1, bm=bm@entry=0x7ffde8ca2dc0,
    to_tag_len=37, to_tag=<optimized out>) at t_reply.c:367
367		rb->buffer.s = (char*)shm_resize( rb->buffer.s, buf_len );
(gdb) p rb
$1 = (struct retr_buf *) 0x7fb41631d550
(gdb) p *rb
$2 = {activ_type = 500, buffer = {s = 0x0, len = 0}, dst = {proto = 3, proto_reserved1 = 443263502, to = {s = {sa_family = 2,
        sa_data = "\023\305\022\350\035z\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 50451, sin_addr = {s_addr = 2048780306},
        sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 50451, sin6_flowinfo = 2048780306, 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}},
    send_sock = 0x7fb450715c80}, retr_timer = {next_tl = 0x0, prev_tl = 0x0, ld_tl = 0x0, time_out = 0, timer_list = 0x0, deleted = 0, set = 2}, fr_timer = {
    next_tl = 0x0, prev_tl = 0x0, ld_tl = 0x0, time_out = 0, timer_list = 0x0, deleted = 0, set = 2}, retr_list = FR_TIMER_LIST, my_T = 0x7fb41631d450,
  branch = 0}
(gdb) p rb->buffer
$3 = {s = 0x0, len = 0}

I will work on reproducing with the debug flags set.

[bcnewlin]

Here is a new core dump with the debug flags compiled in.
core.7659.6.1579105943.txt