[CRASH] Crash in TLS

[adigeo]

OpenSIPS version you are running

version: opensips 3.1.0-dev (x86_64/linux)
flags: STATS: On, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, Q_MALLOC, F_MALLOC, HP_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: d879b36e9
main.c compiled on  with gcc 8

Crash Core Dump

Describe the traffic that generated the bug

Unclear what traffic caused this crash.

To Reproduce

Unclear how to reproduce this crash as it happened during live traffic.

Relevant System Logs

agp@sip-thor-node-01:/cores$ sudo gdb /usr/sbin/opensips core.13634.opensips.1602366266 
GNU gdb (Debian 8.2.1-2+b3) 8.2.1
Reading symbols from /usr/sbin/opensips...(no debugging symbols found)...done.
[New LWP 13634]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/sbin/opensips -w /run/opensips -P opensips.pid -a Q_MALLOC_DBG -m 1536'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00007f7f643108e3 in CRYPTO_set_ex_data () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
(gdb) bt
#0  0x00007f7f643108e3 in CRYPTO_set_ex_data () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
#1  0x00007f7f64586918 in ?? () from /usr/lib/x86_64-linux-gnu/opensips/modules/proto_tls.so
#2  0x000055e4f4acc02b in ?? ()
#3  0x000055e4f4acdfb1 in tcp_worker_proc_loop ()
#4  0x000055e4f4ade2cb in tcp_start_processes ()
#5  0x000055e4f495c813 in main ()
(gdb) 

OS/environment information

• Operating System: Debian Buster 10
• OpenSIPS installation: git 3319120 / Thu Oct 1
• other relevant information:

Additional context

Core dump file http://download.ag-projects.com/cores/core.13634.opensips.1602366266.gz

[adigeo]

Another one similar

Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/sbin/opensips -w /run/opensips -P opensips.pid -a Q_MALLOC_DBG -m 1536'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00007f7f643108e3 in CRYPTO_set_ex_data () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
(gdb) bt
#0  0x00007f7f643108e3 in CRYPTO_set_ex_data () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
#1  0x00007f7f64586918 in ?? () from /usr/lib/x86_64-linux-gnu/opensips/modules/proto_tls.so
#2  0x000055e4f4acc02b in ?? ()
#3  0x000055e4f4acdfb1 in tcp_worker_proc_loop ()
#4  0x000055e4f4ade2cb in tcp_start_processes ()
#5  0x000055e4f495c813 in main ()
(gdb) 

http://download.ag-projects.com/cores/core.13635.opensips.1602366247.gz

[razvancrainea]

Hi, @adigeo !

Can you install debug symbols, so we can figure out exactly how it gets to to the ssl lib?

Cheers,
Răzvan

[adigeo]

http://download.ag-projects.com/cores/core.13635.opensips.1602366247.gz

[New LWP 13635]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/sbin/opensips -w /run/opensips -P opensips.pid -a Q_MALLOC_DBG -m 1536'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00007f7f643108e3 in CRYPTO_set_ex_data () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
(gdb) bt
#0  0x00007f7f643108e3 in CRYPTO_set_ex_data () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
#1  0x00007f7f64586918 in tls_conn_init (api=<optimized out>, api=<optimized out>, c=<optimized out>) at ../tls_mgm/tls_conn_ops.h:145
#2  proto_tls_conn_init (c=0x7f7fb0fde070) at proto_tls.c:363
#3  0x000055e4f4acc02b in handle_io (fm=<optimized out>, idx=idx@entry=26, event_type=event_type@entry=1) at net/net_tcp_proc.c:240
#4  0x000055e4f4acdfb1 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:305
#5  tcp_worker_proc_loop () at net/net_tcp_proc.c:422
#6  0x000055e4f4ade2cb in tcp_start_processes (chd_rank=chd_rank@entry=0x55e4f4cbd5c8 <chd_rank>, startup_done=startup_done@entry=0x0) at net/net_tcp.c:2088
#7  0x000055e4f495c813 in main_loop () at main.c:810
#8  main (argc=<optimized out>, argv=<optimized out>) at main.c:1491
(gdb) 

[adigeo]

Coresponds to http://download.ag-projects.com/cores/core.13634.opensips.1602366266.gz

[New LWP 13634]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/sbin/opensips -w /run/opensips -P opensips.pid -a Q_MALLOC_DBG -m 1536'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00007f7f643108e3 in CRYPTO_set_ex_data () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
(gdb) bt
#0  0x00007f7f643108e3 in CRYPTO_set_ex_data () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
#1  0x00007f7f64586918 in tls_conn_init (api=<optimized out>, api=<optimized out>, c=<optimized out>) at ../tls_mgm/tls_conn_ops.h:145
#2  proto_tls_conn_init (c=0x7f7fc44f91c8) at proto_tls.c:363
#3  0x000055e4f4acc02b in handle_io (fm=<optimized out>, idx=idx@entry=28, event_type=event_type@entry=1) at net/net_tcp_proc.c:240
#4  0x000055e4f4acdfb1 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:305
#5  tcp_worker_proc_loop () at net/net_tcp_proc.c:422
#6  0x000055e4f4ade2cb in tcp_start_processes (chd_rank=chd_rank@entry=0x55e4f4cbd5c8 <chd_rank>, startup_done=startup_done@entry=0x0) at net/net_tcp.c:2088
#7  0x000055e4f495c813 in main_loop () at main.c:810
#8  main (argc=<optimized out>, argv=<optimized out>) at main.c:1491
(gdb) 

[rvlad-patrascu]

Hi @adigeo ,

Can you open the core file and run:

f 1
p *dom
p dom->ctx[process_no]
p c->extra_data

Also, do you see any errors or anything suspicious regarding the tls_mgm or proto_tls modules in the logs?

[adigeo]

Reading symbols from opensips...Reading symbols from /usr/lib/debug/.build-id/2a/c7eca38e1ec3852fedd4d8d4cb109f92e1cd45.debug...done.
done.
[New LWP 13634]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/sbin/opensips -w /run/opensips -P opensips.pid -a Q_MALLOC_DBG -m 1536'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00007f7f643108e3 in CRYPTO_set_ex_data () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
(gdb) f 1
#1  0x00007f7f64586918 in tls_conn_init (api=<optimized out>, api=<optimized out>, c=<optimized out>) at ../tls_mgm/tls_conn_ops.h:145
145	../tls_mgm/tls_conn_ops.h: No such file or directory.
(gdb) p *dom
$1 = {name = {s = 0x7f7f646ae8e8 "server-default", len = 14}, flags = 1, match_domains = 0x7f7f646aeaa0, match_addresses = 0x7f7f646ae9c0, ssl_ex_index = 0, 
  ctx = 0x7f7f647a3838, ctx_no = 37, verify_cert = 1, require_client_cert = 0, crl_check_all = 0, cert = {s = 0x55e4f580aa60 "/etc/opensips/tls/default.crt", 
    len = 29}, pkey = {s = 0x55e4f580ac90 "/etc/opensips/tls/default.key", len = 29}, crl_directory = 0x0, ca = {
    s = 0x55e4f580aec0 "/etc/opensips/tls/ca-list.pem", len = 29}, dh_param = {s = 0x0, len = 0}, tls_ec_curve = 0x0, 
  ca_directory = 0x55e4f5808720 "/etc/ssl/certs", ciphers_list = 0x0, refs = 1, lock = 0x7f7f646ae958, method = TLS_USE_TLSv1, method_max = TLS_USE_TLSv1_3, 
  next = 0x0}
(gdb) p dom->ctx[process_no]
$2 = (void *) 0x7f7f64896370
(gdb) p c->extra_data
value has been optimized out
(gdb) 

[razvancrainea]

Could you also print p process_no?

[adigeo]

#7  0x000055e4f495c813 in main_loop () at main.c:810
#8  main (argc=<optimized out>, argv=<optimized out>) at main.c:1491
(gdb) p process_no
$1 = 13
(gdb) 

[adigeo]

Not sure if related but the crash is in the same module

sudo gdb opensips  core.30770.opensips.1602913979 

GNU gdb (Debian 8.2.1-2+b3) 8.2.1
Copyright (C) 2018 Free Software Foundation, Inc.

Reading symbols from opensips...Reading symbols from /usr/lib/debug/.build-id/2a/c7eca38e1ec3852fedd4d8d4cb109f92e1cd45.debug...done.
done.
[New LWP 30770]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/sbin/opensips -w /run/opensips -P opensips.pid -a F_MALLOC_DBG -m 512'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00007f3d83b608e3 in CRYPTO_set_ex_data () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
(gdb) bt
#0  0x00007f3d83b608e3 in CRYPTO_set_ex_data () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
#1  0x00007f3d83dd6918 in tls_conn_init (api=<optimized out>, api=<optimized out>, c=<optimized out>) at ../tls_mgm/tls_conn_ops.h:145
#2  proto_tls_conn_init (c=0x7f3d86f61a08) at proto_tls.c:363
#3  0x0000558abdac102b in handle_io (fm=<optimized out>, idx=idx@entry=29, event_type=event_type@entry=1) at net/net_tcp_proc.c:240
#4  0x0000558abdac2fb1 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:305
#5  tcp_worker_proc_loop () at net/net_tcp_proc.c:422
#6  0x0000558abdad32cb in tcp_start_processes (chd_rank=chd_rank@entry=0x558abdcb25c8 <chd_rank>, startup_done=startup_done@entry=0x0)
    at net/net_tcp.c:2088
#7  0x0000558abd951813 in main_loop () at main.c:810
#8  main (argc=<optimized out>, argv=<optimized out>) at main.c:1491
(gdb) 

[adigeo]

Another one

sudo gdb opensips  core.5674.opensips.1603089739  

GNU gdb (Debian 8.2.1-2+b3) 8.2.1
Reading symbols from opensips...Reading symbols from /usr/lib/debug/.build-id/2a/c7eca38e1ec3852fedd4d8d4cb109f92e1cd45.debug...done.
done.
[New LWP 5674]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/usr/sbin/opensips -w /run/opensips -P opensips.pid -a F_MALLOC_DBG -m 512'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00007fe876d608e3 in CRYPTO_set_ex_data () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
(gdb) bt
#0  0x00007fe876d608e3 in CRYPTO_set_ex_data () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
#1  0x00007fe876fd6918 in tls_conn_init (api=<optimized out>, api=<optimized out>, c=<optimized out>) at ../tls_mgm/tls_conn_ops.h:145
#2  proto_tls_conn_init (c=0x7fe895249fd0) at proto_tls.c:363
#3  0x000056034ed9002b in handle_io (fm=<optimized out>, idx=idx@entry=35, event_type=event_type@entry=1) at net/net_tcp_proc.c:240
#4  0x000056034ed91fb1 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:305
#5  tcp_worker_proc_loop () at net/net_tcp_proc.c:422
#6  0x000056034eda22cb in tcp_start_processes (chd_rank=chd_rank@entry=0x56034ef815c8 <chd_rank>, startup_done=startup_done@entry=0x0)
    at net/net_tcp.c:2088
#7  0x000056034ec20813 in main_loop () at main.c:810
#8  main (argc=<optimized out>, argv=<optimized out>) at main.c:1491
(gdb) 

[razvancrainea]

I've just commited 32f739b, which addresses the effect of the bug, not the crash itself. Can you apply this patch on your sources and see what are the errors reported by openssl?

Best regards,
Răzvan

[adigeo]

I have rebuilt it. Trying to decipher your last message, will the crash still happen but we get more logs?

[razvancrainea]

Hard to say - the commit itself should prevent the crash, however if there's a memory corruption, it might as well crash somewhere else.