Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[CRASH] Crash in proto_tcp #2291

Closed
adigeo opened this issue Oct 20, 2020 · 15 comments
Closed

[CRASH] Crash in proto_tcp #2291

adigeo opened this issue Oct 20, 2020 · 15 comments
Assignees
Milestone

Comments

@adigeo
Copy link

adigeo commented Oct 20, 2020

OpenSIPS version you are running

version: opensips 3.1.0 (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: 3319120fb
main.c compiled on  with gcc 8```

**Crash Core Dump**
<!--
*Please* DO NOT post the content of the corefile here, but rather provide *a link* to a place (dropbox, pastebin, gdrive) where you stored the output of the core dump.
If you don't have a core dump, please generate one according to the steps described here:
https://www.opensips.org/Documentation/TroubleShooting-Crash
-->

**Describe the traffic that generated the bug**
<!--
Please describe what kind of traffic made OpenSIPS crash
-->

Unknow traffic

**To Reproduce**
<!--
Steps to reproduce the behavior:
Example:
1. Start OpenSIPS
2. Start traffic
3. Check OpenSIPS crashed
-->

**Relevant System Logs**
<!--
Please provide, in ticks block (```example```), relevant information from the system logs
-->

sudo gdb opensips core.18532.opensips.1602799880 

[New LWP 18532]
[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 SIGABRT, Aborted.
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007f400a752535 in __GI_abort () at abort.c:79
#2 0x000056033c94787e in build_res_buf_from_sip_res (msg=msg@entry=0x560342cb8600, returned_len=returned_len@entry=0x7fff2ed27664,
sock=, flags=flags@entry=0) at msg_translator.c:2419
#3 0x00007f3fe9688a1d in relay_reply (t=0x7f3fec518c00, p_msg=, branch=0, msg_status=200,
cancel_bitmap=0x7fff2ed27754) at t_reply.c:1282
#4 0x00007f3fe968af9d in reply_received (p_msg=0x560342cb8600) at t_reply.c:1647
#5 0x000056033c91dad8 in forward_reply (msg=msg@entry=0x560342cb8600) at forward.c:499
#6 0x000056033c9066c7 in receive_msg (
buf=0x56033cc72ac0 <tcp_current_req> "SIP/2.0 200 OK\r\nVia: SIP/2.0/TCP 81.23.228.180:5060;branch=z9hG4bK0bed.86362ac.0\r\nVia: SIP/2.0/UDP 10.0.1.115:33503;received=95.238.189.100;rport=61791;branch=z9hG4bKPj05a40413-4fc5-4a98-ba0e-9a3228df"...,
len=, len@entry=2205, rcv_info=rcv_info@entry=0x7fff2ed279c0, existing_context=existing_context@entry=0x0,
msg_flags=msg_flags@entry=0) at receive.c:266
#7 0x000056033ca7aba5 in tcp_handle_req (_max_msg_chunks=, con=0x7f3fee2e4100, req=0x56033cc72ac0 <tcp_current_req>)
at net/proto_tcp/tcp_common.h:411
#8 tcp_read_req (con=, bytes_read=0x7fff2ed27a80) at net/proto_tcp/proto_tcp.c:1197
#9 0x000056033ca5ac7a in handle_io (fm=, idx=idx@entry=16, event_type=event_type@entry=1) at net/net_tcp_proc.c:312
#10 0x000056033ca5cfb1 in io_wait_loop_epoll (h=, t=, repeat=)
at net/../io_wait_loop.h:305
#11 tcp_worker_proc_loop () at net/net_tcp_proc.c:422
#12 0x000056033ca6d2cb in tcp_start_processes (chd_rank=chd_rank@entry=0x56033cc4c5c8 <chd_rank>,
startup_done=startup_done@entry=0x0) at net/net_tcp.c:2088
#13 0x000056033c8eb813 in main_loop () at main.c:810
#14 main (argc=, argv=) at main.c:1491
(gdb)

**OS/environment information**
 - Operating System: Debian 10
 - OpenSIPS installation: GIT 3319120fb8feed88027576ca45031c99455cd40a
 - other relevant information:

**Additional context**
<!-- Add any other context about the problem here. -->
@adigeo
Copy link
Author

adigeo commented Oct 20, 2020

Another similar one:

sudo gdb opensips core.30088.opensips.1602800973 

[New LWP 30088]
[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 SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007f3fe6402535 in __GI_abort () at abort.c:79
#2  0x0000559bd2a3d87e in build_res_buf_from_sip_res (msg=msg@entry=0x559bd32c3610, returned_len=returned_len@entry=0x7ffcb4704834, 
    sock=<optimized out>, flags=flags@entry=0) at msg_translator.c:2419
#3  0x00007f3fc5330a1d in relay_reply (t=0x7f3fc9119af8, p_msg=<optimized out>, branch=0, msg_status=200, cancel_bitmap=0x7ffcb4704924)
    at t_reply.c:1282
#4  0x00007f3fc5332f9d in reply_received (p_msg=0x559bd32c3610) at t_reply.c:1647
#5  0x0000559bd2a13ad8 in forward_reply (msg=msg@entry=0x559bd32c3610) at forward.c:499
#6  0x0000559bd29fc6c7 in receive_msg (
    buf=0x559bd2d68ac0 <tcp_current_req> "SIP/2.0 200 OK\r\nVia: SIP/2.0/TCP 81.23.228.180:5060;branch=z9hG4bKfe16.321e956.0;rport=5060\r\nVia: SIP/2.0/UDP 10.0.1.115:33503;received=95.238.189.100;rport=61791;branch=z9hG4bKPjc605eeb3-1d1c-46e9-ab"..., len=<optimized out>, 
    len@entry=2855, rcv_info=rcv_info@entry=0x7ffcb4704b90, existing_context=existing_context@entry=0x0, msg_flags=msg_flags@entry=0)
    at receive.c:266
#7  0x0000559bd2b70ba5 in tcp_handle_req (_max_msg_chunks=<optimized out>, con=0x7f3fc78c8570, req=0x559bd2d68ac0 <tcp_current_req>)
    at net/proto_tcp/tcp_common.h:411
#8  tcp_read_req (con=<optimized out>, bytes_read=0x7ffcb4704c50) at net/proto_tcp/proto_tcp.c:1197
#9  0x0000559bd2b50c7a in handle_io (fm=<optimized out>, idx=idx@entry=22, event_type=event_type@entry=1) at net/net_tcp_proc.c:312
#10 0x0000559bd2b52fb1 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:305
#11 tcp_worker_proc_loop () at net/net_tcp_proc.c:422
#12 0x0000559bd2b632cb in tcp_start_processes (chd_rank=chd_rank@entry=0x559bd2d425c8 <chd_rank>, startup_done=startup_done@entry=0x0)
    at net/net_tcp.c:2088
#13 0x0000559bd29e1813 in main_loop () at main.c:810
#14 main (argc=<optimized out>, argv=<optimized out>) at main.c:1491

@adigeo
Copy link
Author

adigeo commented Oct 20, 2020

Another one

sudo gdb opensips core.26907.opensips.1603177037

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 26907]
[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 SIGABRT, Aborted.
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007fa9d0ed5535 in __GI_abort () at abort.c:79
#2 0x000055fc859fa87e in build_res_buf_from_sip_res (msg=msg@entry=0x55fc88fef430, returned_len=returned_len@entry=0x7ffe812b4754,
sock=, flags=flags@entry=0) at msg_translator.c:2419
#3 0x00007fa9afe5ba1d in relay_reply (t=0x7fa9b513c170, p_msg=, branch=0, msg_status=200, cancel_bitmap=0x7ffe812b4844)
at t_reply.c:1282
#4 0x00007fa9afe5df9d in reply_received (p_msg=0x55fc88fef430) at t_reply.c:1647
#5 0x000055fc859d0ad8 in forward_reply (msg=msg@entry=0x55fc88fef430) at forward.c:499
#6 0x000055fc859b96c7 in receive_msg (
buf=0x55fc85d25ac0 <tcp_current_req> "SIP/2.0 200 OK\r\nVia: SIP/2.0/TCP 85.17.186.23:5060;branch=z9hG4bK3d69.d1e4e36.0;i=3be8c1f7;rport=5060\r\nVia: SIP/2.0/TCP 192.168.1.8:51314;received=194.26.164.10;rport=35565;branch=z9hG4bKPjhK4LqCtoCgp"..., len=,
len@entry=1608, rcv_info=rcv_info@entry=0x7ffe812b4ab0, existing_context=existing_context@entry=0x0, msg_flags=msg_flags@entry=0)
at receive.c:266
#7 0x000055fc85b2dba5 in tcp_handle_req (_max_msg_chunks=, con=0x7fa9b26c2718, req=0x55fc85d25ac0 <tcp_current_req>)
at net/proto_tcp/tcp_common.h:411
#8 tcp_read_req (con=, bytes_read=0x7ffe812b4b70) at net/proto_tcp/proto_tcp.c:1197
#9 0x000055fc85b0dc7a in handle_io (fm=, idx=idx@entry=33, event_type=event_type@entry=1) at net/net_tcp_proc.c:312
#10 0x000055fc85b0ffb1 in io_wait_loop_epoll (h=, t=, repeat=) at net/../io_wait_loop.h:305
#11 tcp_worker_proc_loop () at net/net_tcp_proc.c:422
#12 0x000055fc85b202cb in tcp_start_processes (chd_rank=chd_rank@entry=0x55fc85cff5c8 <chd_rank>, startup_done=startup_done@entry=0x0)
at net/net_tcp.c:2088
#13 0x000055fc8599e813 in main_loop () at main.c:810
#14 main (argc=, argv=) at main.c:1491
(gdb)

@razvancrainea
Copy link
Member

The last two core dumps are generated by an abort, caused by a lumps mismatch. Both of them print some messages in the logs - can you show us those logs as well?

@adigeo
Copy link
Author

adigeo commented Oct 28, 2020

We only have logs for maximum 10 days :-(

But I have a more recent one, I come back with the logs for it.

@adigeo
Copy link
Author

adigeo commented Oct 28, 2020

agp@sip-thor-node-01:~$ sudo gdb opensips /cores/core.2681.opensips.1603595593
Reading symbols from opensips...Reading symbols from /usr/lib/debug/.build-id/b2/103bbb33df29242ebe4014be8695654fac86a4.debug...done.
done.
[New LWP 2681]
[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 SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007ffbc87f2535 in __GI_abort () at abort.c:79
#2  0x00005626df992fa6 in fm_free_dbg (fm=<optimized out>, p=0x7ffbaa4024d8, file=<optimized out>, func=<optimized out>, line=<optimized out>)
    at mem/f_malloc_dyn.h:221
#3  0x00007ffba838d403 in _shm_free (line=450, function=<synthetic pointer>, file=0x7ffba85f55ac "../crypto/err/err.c", ptr=0x7ffbaa4024d8)
    at ../../mem/shm_mem.h:448
#4  os_free (ptr=0x7ffbaa4024d8, file=0x7ffba85f55ac "../crypto/err/err.c", line=450) at tls.h:123
#5  0x00007ffba851347c in ERR_clear_error () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
#6  0x00007ffba87aaf76 in tls_write (c=c@entry=0x7ffbaa11abc0, buf=buf@entry=0x7ffbacecddb8, len=len@entry=856, 
    poll_events=poll_events@entry=0x7ffdc604242c, fd=<optimized out>) at ../tls_mgm/tls_conn_server.h:561
#7  0x00007ffba87b1b43 in tls_blocking_write (t_dst=0x0, send_timeout=2000, handshake_timeout=5000, len=856, 
    buf=0x7ffbacecddb8 "NOTIFY sip:01435279@162.224.10.178:50625;transport=tls SIP/2.0\r\nRecord-Route: <sip:81.23.228.180:5061;transport=tls;r2=on;lr;ftag=2be0-248ad6189a6945ae551af3bef17981b5>\r\nRecord-Route: <sip:81.23.228.1"..., fd=<optimized out>, c=0x7ffbaa11abc0)
    at ../tls_mgm/tls_conn_server.h:638
#8  proto_tls_send (send_sock=<optimized out>, buf=<optimized out>, len=<optimized out>, to=<optimized out>, id=<optimized out>)
    at proto_tls.c:505
#9  0x00007ffba7724020 in msg_send (msg=0x0, len=<optimized out>, 
    buf=0x7ffbacecddb8 "NOTIFY sip:01435279@162.224.10.178:50625;transport=tls SIP/2.0\r\nRecord-Route: <sip:81.23.228.180:5061;transport=tls;r2=on;lr;ftag=2be0-248ad6189a6945ae551af3bef17981b5>\r\nRecord-Route: <sip:81.23.228.1"..., id=<optimized out>, to=0x7ffbac8f4688, proto=3, 
    send_sock=0x5626e0d54550) at ../../forward.h:123
#10 send_pr_buffer (rb=rb@entry=0x7ffbac8f4668, buf=0x7ffbacecddb8, len=<optimized out>, ctx=ctx@entry=0x0) at t_funcs.c:68
#11 0x00007ffba7764578 in t_forward_nonack (t=t@entry=0x7ffbac8f4490, p_msg=p_msg@entry=0x5626e127ed60, proxy=proxy@entry=0x0, 
    reset_bcounter=reset_bcounter@entry=0, locked=locked@entry=0) at t_fwd.c:835
#12 0x00007ffba7725cb3 in t_relay_to (p_msg=p_msg@entry=0x5626e127ed60, proxy=proxy@entry=0x0, flags=flags@entry=4) at t_funcs.c:260
#13 0x00007ffba773d5e4 in w_t_relay (p_msg=0x5626e127ed60, flags=0x4, proxy=<optimized out>) at tm.c:1197
#14 0x00005626df8e306e in do_action (a=0x5626e0eafb90, msg=0x5626e127ed60) at action.c:972
#15 0x00005626df8e5398 in run_action_list (a=<optimized out>, msg=msg@entry=0x5626e127ed60) at action.c:157
#16 0x00005626df8e4dfe in do_action (a=0x5626e0ec3240, msg=0x5626e127ed60) at action.c:755
#17 0x00005626df8e5398 in run_action_list (a=<optimized out>, msg=msg@entry=0x5626e127ed60) at action.c:157
--Type <RET> for more, q to quit, c to continue without paging--  
#18 0x00005626df8e4e91 in do_action (a=0x5626e0ec3340, msg=0x5626e127ed60) at action.c:761
#19 0x00005626df8e5398 in run_action_list (a=<optimized out>, msg=msg@entry=0x5626e127ed60) at action.c:157
#20 0x00005626df8e4e91 in do_action (a=0x5626e0ec3440, msg=0x5626e127ed60) at action.c:761
#21 0x00005626df8e5398 in run_action_list (a=<optimized out>, msg=msg@entry=0x5626e127ed60) at action.c:157
#22 0x00005626df8e4e91 in do_action (a=0x5626e0ec3540, msg=0x5626e127ed60) at action.c:761
#23 0x00005626df8e5398 in run_action_list (a=<optimized out>, msg=msg@entry=0x5626e127ed60) at action.c:157
#24 0x00005626df8e4e91 in do_action (a=0x5626e0ec3640, msg=0x5626e127ed60) at action.c:761
#25 0x00005626df8e5398 in run_action_list (a=<optimized out>, msg=msg@entry=0x5626e127ed60) at action.c:157
#26 0x00005626df8e4e91 in do_action (a=0x5626e0ec3740, msg=0x5626e127ed60) at action.c:761
#27 0x00005626df8e5398 in run_action_list (a=a@entry=0x5626e0e16610, msg=msg@entry=0x5626e127ed60) at action.c:157
#28 0x00005626df8e57e7 in run_actions (msg=0x5626e127ed60, a=0x5626e0e16610) at action.c:122
#29 run_actions (msg=0x5626e127ed60, a=0x5626e0e16610) at action.c:103
#30 run_top_route (a=0x5626e0e16610, msg=msg@entry=0x5626e127ed60) at action.c:240
#31 0x00005626df8f3b36 in receive_msg (
    buf=0x5626dfc4faa0 <tcp_current_req> "NOTIFY sip:01435279@162.224.10.178:50625;transport=tls SIP/2.0\r\nVia: SIP/2.0/TCP 85.17.186.23:5060;branch=z9hG4bKff8e.c9305f22.0\r\nTo: <sip:wrblink@sip2sip.info>;tag=f86e057c783140a2b7eb565f51918df6\r\nF"..., len=<optimized out>, 
    len@entry=706, rcv_info=rcv_info@entry=0x7ffdc6043860, existing_context=existing_context@entry=0x0, msg_flags=msg_flags@entry=0)
    at receive.c:213
#32 0x00005626dfa57ba5 in tcp_handle_req (_max_msg_chunks=<optimized out>, con=0x7ffba9c8fbf0, req=0x5626dfc4faa0 <tcp_current_req>)
    at net/proto_tcp/tcp_common.h:411
#33 tcp_read_req (con=<optimized out>, bytes_read=0x7ffdc6043920) at net/proto_tcp/proto_tcp.c:1197
#34 0x00005626dfa37c7a in handle_io (fm=<optimized out>, idx=idx@entry=0, event_type=event_type@entry=1) at net/net_tcp_proc.c:312
#35 0x00005626dfa39fb1 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:305
#36 tcp_worker_proc_loop () at net/net_tcp_proc.c:422
#37 0x00005626dfa4a2cb in tcp_start_processes (chd_rank=chd_rank@entry=0x5626dfc295a8 <chd_rank>, startup_done=startup_done@entry=0x0)
    at net/net_tcp.c:2088
#38 0x00005626df8c8813 in main_loop () at main.c:810
#39 main (argc=<optimized out>, argv=<optimized out>) at main.c:1491
(gdb) 

Corespondent Logs

Oct 25 04:13:12 sip-thor-node-01 /usr/sbin/opensips[2680]: ERROR:domain:is_from_local: Error while parsing From header
Oct 25 04:13:12 sip-thor-node-01 /usr/sbin/opensips[2680]: ERROR:core:parse_uri: bad char '@' in state 5 parsed: <sip:trieuvn@sip2sip.info> (24) / <sip:trieuvn@sip2sip.info@sip2sip.info> (37)
Oct 25 04:13:12 sip-thor-node-01 /usr/sbin/opensips[2680]: ERROR:core:parse_from_uri: failed to parse From uri
Oct 25 04:13:12 sip-thor-node-01 /usr/sbin/opensips[2680]: ERROR:domain:is_from_local: Error while parsing From header
Oct 25 04:13:12 sip-thor-node-01 /usr/sbin/opensips[2679]: ERROR:core:parse_uri: bad char '@' in state 5 parsed: <sip:trieuvn@sip2sip.info> (24) / <sip:trieuvn@sip2sip.info@sip2sip.info> (37)
Oct 25 04:13:12 sip-thor-node-01 /usr/sbin/opensips[2679]: ERROR:core:parse_from_uri: failed to parse From uri
Oct 25 04:13:12 sip-thor-node-01 /usr/sbin/opensips[2679]: ERROR:domain:is_from_local: Error while parsing From header
Oct 25 04:13:12 sip-thor-node-01 /usr/sbin/opensips[2679]: ERROR:core:parse_uri: bad char '@' in state 5 parsed: <sip:trieuvn@sip2sip.info> (24) / <sip:trieuvn@sip2sip.info@sip2sip.info> (37)
Oct 25 04:13:12 sip-thor-node-01 /usr/sbin/opensips[2679]: ERROR:core:parse_from_uri: failed to parse From uri
Oct 25 04:13:12 sip-thor-node-01 /usr/sbin/opensips[2679]: ERROR:domain:is_from_local: Error while parsing From header
Oct 25 04:13:12 sip-thor-node-01 /usr/sbin/opensips[2683]: ERROR:proto_tls:tls_accept: New TLS connection from 104.254.10.117:47398 failed to accept
Oct 25 04:13:12 sip-thor-node-01 /usr/sbin/opensips[2683]: ERROR:proto_tls:tls_print_errstack: TLS errstack: error:14094415:SSL routines:ssl3_read_bytes:sslv3 alert certificate expired
Oct 25 04:13:12 sip-thor-node-01 /usr/sbin/opensips[2683]: ERROR:proto_tls:tls_read_req: failed to do pre-tls reading
Oct 25 04:13:13 sip-thor-node-01 /usr/sbin/opensips[2683]: ERROR:proto_tls:tls_accept: New TLS connection from 104.254.10.117:43264 failed to accept
Oct 25 04:13:13 sip-thor-node-01 /usr/sbin/opensips[2683]: ERROR:proto_tls:tls_print_errstack: TLS errstack: error:14094415:SSL routines:ssl3_read_bytes:sslv3 alert certificate expired
Oct 25 04:13:13 sip-thor-node-01 /usr/sbin/opensips[2683]: ERROR:proto_tls:tls_read_req: failed to do pre-tls reading
Oct 25 04:13:13 sip-thor-node-01 /usr/sbin/opensips[2681]: CRITICAL:core:fm_free_dbg: freeing already freed shm pointer (0x7ffbaa4024d8), first free: ../crypto/err/err.c: os_free(569) - aborting!
Oct 25 04:13:22 sip-thor-node-01 /usr/sbin/opensips[2671]: CRITICAL:db_mysql:wrapper_single_mysql_stmt_execute: driver error (1062): Duplicate entry '3359078292676602516' for key 'PRIMARY'
Oct 25 04:13:22 sip-thor-node-01 /usr/sbin/opensips[2671]: ERROR:usrloc:db_insert_ucontact: inserting contact in db failed
Oct 25 04:13:22 sip-thor-node-01 /usr/sbin/opensips[2671]: ERROR:usrloc:wb_timer: inserting contact into database failed

@adigeo
Copy link
Author

adigeo commented Oct 28, 2020

agp@sip-thor-node-01:~$ sudo gdb opensips  /cores/core.620.opensips.1603649594
Reading symbols from opensips...Reading symbols from /usr/lib/debug/.build-id/b2/103bbb33df29242ebe4014be8695654fac86a4.debug...done.
done.
[New LWP 620]
[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 SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007f258acda535 in __GI_abort () at abort.c:79
#2  0x000055a587809fa6 in fm_free_dbg (fm=<optimized out>, p=0x7f256cb8fea8, file=<optimized out>, func=<optimized out>, line=<optimized out>)
    at mem/f_malloc_dyn.h:221
#3  0x00007f256a875403 in _shm_free (line=569, function=<synthetic pointer>, file=0x7f256aadd5ac "../crypto/err/err.c", ptr=0x7f256cb8fea8)
    at ../../mem/shm_mem.h:448
#4  os_free (ptr=0x7f256cb8fea8, file=0x7f256aadd5ac "../crypto/err/err.c", line=569) at tls.h:123
#5  0x00007f256a9fb7fd in ?? () from /usr/lib/x86_64-linux-gnu/libcrypto.so.1.1
#6  0x00007f256ac8cc54 in tls_print_errstack () at ../tls_mgm/tls_conn.h:53
#7  0x00007f256ac90985 in tls_accept (c=c@entry=0x7f256d0d6a90, poll_events=poll_events@entry=0x0) at ../tls_mgm/tls_conn_server.h:361
#8  0x00007f256ac96f59 in tls_fix_read_conn (t_dst=0x0, c=0x7f256d0d6a90) at ../tls_mgm/tls_conn_server.h:533
#9  tls_read_req (con=0x7f256d0d6a90, bytes_read=0x7fff90bceac0) at proto_tls.c:557
#10 0x000055a5878aec7a in handle_io (fm=<optimized out>, idx=idx@entry=23, event_type=event_type@entry=1) at net/net_tcp_proc.c:312
#11 0x000055a5878b0fb1 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:305
#12 tcp_worker_proc_loop () at net/net_tcp_proc.c:422
#13 0x000055a5878c12cb in tcp_start_processes (chd_rank=chd_rank@entry=0x55a587aa05a8 <chd_rank>, startup_done=startup_done@entry=0x0) at net/net_tcp.c:2088
#14 0x000055a58773f813 in main_loop () at main.c:810
#15 main (argc=<optimized out>, argv=<optimized out>) at main.c:1491
(gdb) 

logs

Oct 25 19:13:14 sip-thor-node-01 /usr/sbin/opensips[620]: ERROR:proto_tls:tls_print_errstack: TLS errstack: error:14094415:SSL routines:ssl3_read_bytes:sslv3 alert certificate expired
Oct 25 19:13:14 sip-thor-node-01 /usr/sbin/opensips[620]: ERROR:proto_tls:tls_read_req: failed to do pre-tls reading
Oct 25 19:13:14 sip-thor-node-01 /usr/sbin/opensips[615]: ERROR:presence:handle_subscribe: un-registered support for known event [as-feature-event]
Oct 25 19:13:14 sip-thor-node-01 /usr/sbin/opensips[618]: ERROR:core:parse_msg: message=<>
Oct 25 19:13:14 sip-thor-node-01 /usr/sbin/opensips[618]: ERROR:core:receive_msg: Unable to parse msg received from [31.211.197.140:57800]
Oct 25 19:13:14 sip-thor-node-01 /usr/sbin/opensips[620]: ERROR:proto_tls:tls_accept: New TLS connection from 98.143.78.197:37119 failed to accept
Oct 25 19:13:14 sip-thor-node-01 /usr/sbin/opensips[620]: ERROR:proto_tls:tls_print_errstack: TLS errstack: error:14094415:SSL routines:ssl3_read_bytes:sslv3 alert certificate expired
Oct 25 19:13:14 sip-thor-node-01 /usr/sbin/opensips[620]: ERROR:proto_tls:tls_read_req: failed to do pre-tls reading
Oct 25 19:13:14 sip-thor-node-01 /usr/sbin/opensips[620]: ERROR:proto_tls:tls_accept: New TLS connection from 98.143.78.197:42513 failed to accept
Oct 25 19:13:14 sip-thor-node-01 /usr/sbin/opensips[620]: ERROR:proto_tls:tls_print_errstack: TLS errstack: error:14094415:SSL routines:ssl3_read_bytes:sslv3 alert certificate expired
Oct 25 19:13:14 sip-thor-node-01 /usr/sbin/opensips[620]: ERROR:proto_tls:tls_read_req: failed to do pre-tls reading
Oct 25 19:13:14 sip-thor-node-01 /usr/sbin/opensips[620]: ERROR:proto_tls:tls_accept: New TLS connection from 98.143.78.197:38038 failed to accept
Oct 25 19:13:14 sip-thor-node-01 /usr/sbin/opensips[620]: CRITICAL:core:fm_free_dbg: freeing already freed shm pointer (0x7f256cb8fea8), first free: ../crypto/err/err.c: os_free(450) - aborting!
Oct 25 19:13:15 sip-thor-node-01 /usr/sbin/opensips[617]: ERROR:core:parse_msg: message=<>
Oct 25 19:13:15 sip-thor-node-01 /usr/sbin/opensips[617]: ERROR:core:receive_msg: Unable to parse msg received from [69.106.204.90:5064]
Oct 25 19:13:23 sip-thor-node-01 /usr/sbin/opensips[609]: CRITICAL:core:send_all: send on -1 failed: Bad file descriptor
Oct 25 19:13:23 sip-thor-node-01 /usr/sbin/opensips[609]: ERROR:core:tcp_conn_get: failed to get fd(write):Bad file descriptor (9)
Oct 25 19:13:23 sip-thor-node-01 /usr/sbin/opensips[609]: ERROR:core:proto_tcp_send: failed to acquire connection
Oct 25 19:13:23 sip-thor-node-01 /usr/sbin/opensips[609]: ERROR:tm:msg_send: send() to 85.17.186.23:5060 for proto tcp/2 failed
Oct 25 19:13:23 sip-thor-node-01 /usr/sbin/opensips[609]: ERROR:tm:t_uac: attempt to send to 'sip:85.17.186.23;transport=tcp;r2=on;lr;ftag=8iLgBugbfrWuJW4Y7aC7jxTY786HDe8W' failed

@adigeo
Copy link
Author

adigeo commented Oct 30, 2020

New BT

agp@sip-thor-node-01:~$ sudo gdb opensips /cores/core.5468.opensips.1604087225
Reading symbols from opensips...Reading symbols from /usr/lib/debug/.build-id/92/cc799f8fb7e22954151e419f55c0b885f8c910.debug...done.
done.
[New LWP 5468]
[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 SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007fb01986a535 in __GI_abort () at abort.c:79
#2  0x0000556e9c30dc9e in build_res_buf_from_sip_res (msg=msg@entry=0x556e9ce24500, 
    returned_len=returned_len@entry=0x7ffd01b6a7e4, sock=<optimized out>, flags=flags@entry=0) at msg_translator.c:2419
#3  0x00007faff87a0a1d in relay_reply (t=0x7fb001a73048, p_msg=<optimized out>, branch=0, msg_status=200, 
    cancel_bitmap=0x7ffd01b6a8d4) at t_reply.c:1282
#4  0x00007faff87a2f9d in reply_received (p_msg=0x556e9ce24500) at t_reply.c:1647
#5  0x0000556e9c33f368 in forward_reply (msg=msg@entry=0x556e9ce24500) at forward.c:499
#6  0x0000556e9c328027 in receive_msg (
    buf=0x556e9c681aa0 <tcp_current_req> "SIP/2.0 200 OK\r\nVia: SIP/2.0/TCP 81.23.228.180:5060;branch=z9hG4bK7401.635f9fc4.0;i=5228821\r\nVia: SIP/2.0/TCP 140.242.65.54:5060;rport=14837;received=140.242.65.54;branch=z9hG4bK-3535-489a9b9a407b6002"..., 
    len=<optimized out>, len@entry=1705, rcv_info=rcv_info@entry=0x7ffd01b6ab40, existing_context=existing_context@entry=0x0, 
    msg_flags=msg_flags@entry=0) at receive.c:266
#7  0x0000556e9c4893e5 in tcp_handle_req (_max_msg_chunks=<optimized out>, con=0x7faffaee6160, 
    req=0x556e9c681aa0 <tcp_current_req>) at net/proto_tcp/tcp_common.h:411
#8  tcp_read_req (con=<optimized out>, bytes_read=0x7ffd01b6ac00) at net/proto_tcp/proto_tcp.c:1197
#9  0x0000556e9c4695da in handle_io (fm=<optimized out>, idx=idx@entry=10, event_type=event_type@entry=1)
    at net/net_tcp_proc.c:312
#10 0x0000556e9c46b911 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>)
    at net/../io_wait_loop.h:305
#11 tcp_worker_proc_loop () at net/net_tcp_proc.c:422
#12 0x0000556e9c47bc6b in tcp_start_processes (chd_rank=chd_rank@entry=0x556e9c65b5a8 <chd_rank>, 
    startup_done=startup_done@entry=0x0) at net/net_tcp.c:2088
#13 0x0000556e9c2fd813 in main_loop () at main.c:810
#14 main (argc=<optimized out>, argv=<optimized out>) at main.c:1491
(gdb) 

Logs

Oct 30 20:47:03 sip-thor-node-01 /usr/sbin/opensips[5471]: [CONFIG] Reply for INVITE CALL (02c1b984-820a-4575-a2f4-b49f74d693f5): 200 OK
Oct 30 20:47:03 sip-thor-node-01 media-dispatcher[32152]: INFO     [relay 85.17.186.6] Requesting 'update' for session R44AcIWOhgOs1iOKm/tphg
Oct 30 20:47:03 sip-thor-node-01 /usr/sbin/opensips[5468]: [CONFIG] Sending out ACK request for sip:castleitmxl@201.143.135.254:1054 (02c1b984-820a-4575-a2f4-b49f74d693f5)
Oct 30 20:47:03 sip-thor-node-01 /usr/sbin/opensips[5468]: [CONFIG] ACK sip:castleitmxl@201.143.135.254:1054 CALL from sip:Damian.Castillo@vc.poly.com to sip:castleitmxl@sip2sip.info;transport=tcp via extern tcp:140.242.65.54:14837 (02c1b984-820a-4575-a2f4-b49f74d693f5)
Oct 30 20:47:03 sip-thor-node-01 /usr/sbin/opensips[5468]: [CONFIG] Sending out ACK request for sip:castleitmxl@201.143.135.254:1054 (02c1b984-820a-4575-a2f4-b49f74d693f5)
Oct 30 20:47:04 sip-thor-node-01 /usr/sbin/opensips[5469]: ERROR:proto_tls:tls_accept: New TLS connection from 101.181.116.155:51832 failed to accept
Oct 30 20:47:04 sip-thor-node-01 /usr/sbin/opensips[5469]: ERROR:proto_tls:tls_print_errstack: TLS errstack: error:1417C086:SSL routines:tls_process_client_certificate:certificate verify failed
Oct 30 20:47:04 sip-thor-node-01 /usr/sbin/opensips[5469]: ERROR:proto_tls:tls_read_req: failed to do pre-tls reading
Oct 30 20:47:04 sip-thor-node-01 sshd[10900]: Connection closed by 185.176.220.239 port 59192 [preauth]
Oct 30 20:47:04 sip-thor-node-01 /usr/sbin/opensips[5468]: [CONFIG] INVITE sip:castleitmxl@201.143.135.254:1054 CALL from sip:Damian.Castillo@vc.poly.com to sip:castleitmxl@sip2sip.info;transport=tcp via extern tcp:140.242.65.54:14837 (02c1b984-820a-4575-a2f4-b49f74d693f5)
Oct 30 20:47:04 sip-thor-node-01 media-dispatcher[32152]: INFO     [relay 85.17.186.6] Requesting 'update' for session R44AcIWOhgOs1iOKm/tphg
Oct 30 20:47:04 sip-thor-node-01 /usr/sbin/opensips[5468]: [CONFIG] Sending out INVITE request for sip:castleitmxl@201.143.135.254:1054 (02c1b984-820a-4575-a2f4-b49f74d693f5)
Oct 30 20:47:04 sip-thor-node-01 /usr/sbin/opensips[5468]: [CONFIG] Reply for INVITE CALL (02c1b984-820a-4575-a2f4-b49f74d693f5): 100 Giving it a try
Oct 30 20:47:05 sip-thor-node-01 /usr/sbin/opensips[5468]: [CONFIG] Reply for INVITE CALL (02c1b984-820a-4575-a2f4-b49f74d693f5): 200 OK
Oct 30 20:47:05 sip-thor-node-01 media-dispatcher[32152]: INFO     [relay 85.17.186.6] Requesting 'update' for session R44AcIWOhgOs1iOKm/tphg
Oct 30 20:47:05 sip-thor-node-01 /usr/sbin/opensips[5468]: CRITICAL:core:build_res_buf_from_sip_res: 
                                                           >>> len mismatch : calculated 1696, written 1674
                                                           
                                                           It seems you have hit a programming bug.
                                                           Please help us make OpenSIPS better by reporting it at https://github.com/OpenSIPS/opensips/issues

@adigeo
Copy link
Author

adigeo commented Nov 7, 2020

agp@live02:~/opensips-xs$ sudo gdb opensips /cores/core.17380.opensips.1604438655
GNU gdb (Debian 8.2.1-2+b3) 8.2.1
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from opensips...Reading symbols from /usr/lib/debug/.build-id/46/43585b4d19f3c0d2c850af13d836bb9b7a2b47.debug...done.
done.
[New LWP 17380]
[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 1024'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt full
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
        set = {__val = {0, 94102076924528, 0, 1271739872832562176, 11, 1, 1, 21, 11, 94102076924528, 140736719138528, 
            139686490302997, 0, 94102044114272, 139685443972664, 1604438655}}
        pid = <optimized out>
        tid = <optimized out>
        ret = <optimized out>
#1  0x00007f0b4b955535 in __GI_abort () at abort.c:79
        save_stage = 1
        act = {__sigaction_handler = {sa_handler = 0x5595d8aa45a8, sa_sigaction = 0x5595d8aa45a8}, sa_mask = {__val = {
              94102044117152, 1498, 1474, 94102073525168, 140736719138792, 140736719138796, 94102044117473, 
              94102044117152, 139685415488704, 94102073525192, 1271739872832562176, 139685415488704, 1498, 
              94102077920128, 94102073525104, 94102078421056}}, sa_flags = -769216536, sa_restorer = 0x7fffd226afec}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x00005595d6d09c9e in build_res_buf_from_sip_res (msg=msg@entry=0x5595d8ed5380, 
    returned_len=returned_len@entry=0x7fffd226b094, sock=<optimized out>, flags=flags@entry=0) at msg_translator.c:2419
        new_len = 1498
        body_delta = <optimized out>
        len = 1537
        new_buf = <optimized out>
        buf = <optimized out>
        offset = 1474
        s_offset = 1509
        body = <optimized out>
        __FUNCTION__ = "build_res_buf_from_sip_res"
#3  0x00007f0b0a8dba1d in relay_reply (t=0x7f0b0d182d08, p_msg=<optimized out>, branch=0, msg_status=200, 
    cancel_bitmap=0x7fffd226b184) at t_reply.c:1282
        relay = 0
        save_clone = 0
--Type <RET> for more, q to quit, c to continue without paging--
        buf = 0x0
        res_len = 0
        relayed_code = 200
        relayed_msg = 0x5595d8ed5380
        bm = {to_tag_val = {s = 0x5595d8ed5380 "(\016\001", len = -687271104}}
        totag_retr = 0
        reply_status = <optimized out>
        uas_rb = 0x7f0b0d182e08
        cb_s = {s = 0x0, len = 0}
        text = {s = 0x5595d8ed5380 "(\016\001", len = -690920552}
        __FUNCTION__ = "relay_reply"
#4  0x00007f0b0a8ddf9d in reply_received (p_msg=0x5595d8ed5380) at t_reply.c:1647
        msg_status = 200
        last_uac_status = <optimized out>
        branch = 0
        reply_status = <optimized out>
        timer = 140736719139392
        cancel_bitmap = 0
        uac = 0x7f0b0d182ee0
        t = 0x7f0b0d182d08
        backup_list = <optimized out>
        has_reply_route = <optimized out>
        old_route_type = <optimized out>
        __FUNCTION__ = "reply_received"
#5  0x00005595d6d3b438 in forward_reply (msg=msg@entry=0x5595d8ed5380) at forward.c:499
        new_buf = 0x0
        to = 0x0
        new_len = 0
        mod = 0x5595d8b25ea0
        proto = <optimized out>
        id = 0
        send_sock = <optimized out>
        s = <optimized out>
        len = <optimized out>
        __FUNCTION__ = "forward_reply"
#6  0x00005595d6d24027 in receive_msg (
    buf=buf@entry=0x7f0b0b920cc0 <tls_current_req> "SIP/2.0 200 OK\r\nCSeq: 1827 INVITE\r\nCall-ID: ada133ae52e30690a672a046f9bba1a6@127.0.0.1\r\nFrom: <sip:dsobrinho40@sip2sip.info>;tag=9c493abd6f8447b1bfbe91a08db10ed1\r\nVia: SIP/2.0/TLS 85.17.186.23:5061;br"..., 
    len=<optimized out>, len@entry=1537, rcv_info=rcv_info@entry=0x7fffd226b3c0, existing_context=existing_context@entry=0x0, 
    msg_flags=msg_flags@entry=0) at receive.c:266
        ctx = 0x5595d8dae3d0
--Type <RET> for more, q to quit, c to continue without paging--
        msg = 0x5595d8ed5380
        start = {tv_sec = 139685440141640, tv_usec = 139685412950758}
        rc = 3
        old_route_type = 4
        tmp = <optimized out>
        in_buff = {
          s = 0x7f0b0b920cc0 <tls_current_req> "SIP/2.0 200 OK\r\nCSeq: 1827 INVITE\r\nCall-ID: ada133ae52e30690a672a046f9bba1a6@127.0.0.1\r\nFrom: <sip:dsobrinho40@sip2sip.info>;tag=9c493abd6f8447b1bfbe91a08db10ed1\r\nVia: SIP/2.0/TLS 85.17.186.23:5061;br"..., len = 1537}
        __FUNCTION__ = "receive_msg"
#7  0x00007f0b0b917955 in tcp_handle_req (_max_msg_chunks=<optimized out>, con=0x7f0b0d1dea38, req=0x7f0b0b920cc0 <tls_current_req>)
    at ../../net/proto_tcp/tcp_common.h:411
        local_rcv = {src_ip = {af = 2, len = 4, u = {addrl = {2950225170, 0}, addr32 = {2950225170, 0, 0, 0}, addr16 = {56594, 45016, 0, 0, 0, 
                0, 0, 0}, addr = "\022\335\330\257", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {398070101, 0}, 
              addr32 = {398070101, 0, 0, 0}, addr16 = {4437, 6074, 0, 0, 0, 0, 0, 0}, addr = "U\021\272\027", '\000' <repeats 11 times>}}, 
          src_port = 6793, dst_port = 5061, proto = 3, proto_reserved1 = 1954777275, proto_reserved2 = 0, src_su = {s = {sa_family = 2, 
              sa_data = "\032\211\022\335\330\257\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 35098, sin_addr = {
                s_addr = 2950225170}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 35098, 
              sin6_flowinfo = 2950225170, sin6_addr = {__in6_u = {__u6_addr8 = "\000\000\000\000\000\000\000\000\000\004\000\000\000\000\000", 
                  __u6_addr16 = {0, 0, 0, 0, 1024, 0, 0, 0}, __u6_addr32 = {0, 0, 1024, 0}}}, sin6_scope_id = 1}}, 
          bind_address = 0x5595d8aa4550}
        msg_buf = 0x7f0b0b920cc0 <tls_current_req> "SIP/2.0 200 OK\r\nCSeq: 1827 INVITE\r\nCall-ID: ada133ae52e30690a672a046f9bba1a6@127.0.0.1\r\nFrom: <sip:dsobrinho40@sip2sip.info>;tag=9c493abd6f8447b1bfbe91a08db10ed1\r\nVia: SIP/2.0/TLS 85.17.186.23:5061;br"...
        msg_len = 1537
        c = 112 'p'
        size = 0
        local_rcv = <optimized out>
        msg_buf = <optimized out>
        msg_len = <optimized out>
        size = <optimized out>
        c = <optimized out>
        __FUNCTION__ = "tcp_handle_req"
        _timeout = <optimized out>
#8  tls_read_req (con=0x7f0b0d1dea38, bytes_read=0x7fffd226b480) at proto_tls.c:631
        ret = 0
        bytes = <optimized out>
        total_bytes = 1537
        req = 0x7f0b0b920cc0 <tls_current_req>
        data = <optimized out>
        __FUNCTION__ = "tls_read_req"
#9  0x00005595d6e68c7a in handle_io (fm=<optimized out>, idx=idx@entry=30, event_type=event_type@entry=1) at net/net_tcp_proc.c:312
        ret = 0
        n = <optimized out>
        con = 0x7f0b0d1dea38
        s = 313
--Type <RET> for more, q to quit, c to continue without paging--
        rw = <optimized out>
        resp = <optimized out>
        response = {139685441432120, 1}
        __FUNCTION__ = "handle_io"
#10 0x00005595d6e6afb1 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:305
        ep_event = {events = 8, data = {ptr = 0xd8b5224000000030, fd = 48, u32 = 48, u64 = 15615424941250314288}}
        curr_time = 14995
        ret = <optimized out>
        n = <optimized out>
        r = 30
        e = <optimized out>
        fd = <optimized out>
        i = <optimized out>
        ret = <optimized out>
        n = <optimized out>
        r = <optimized out>
        i = <optimized out>
        e = <optimized out>
        ep_event = <optimized out>
        fd = <optimized out>
        curr_time = <optimized out>
        __FUNCTION__ = "io_wait_loop_epoll"
#11 tcp_worker_proc_loop () at net/net_tcp_proc.c:422
        __FUNCTION__ = "tcp_worker_proc_loop"
#12 0x00005595d6e7b2cb in tcp_start_processes (chd_rank=chd_rank@entry=0x5595d705a5a8 <chd_rank>, startup_done=startup_done@entry=0x0)
    at net/net_tcp.c:2088
        r = <optimized out>
        n = <optimized out>
        p_id = <optimized out>
        reader_fd = {284, 285}
        si = <optimized out>
        __FUNCTION__ = "tcp_start_processes"
#13 0x00005595d6cf9813 in main_loop () at main.c:810
        startup_done = 0x0
        last_check = 0
        rc = <optimized out>
        chd_rank = 8
        startup_done = <optimized out>
        last_check = <optimized out>
        rc = <optimized out>
        __FUNCTION__ = "main_loop"
#14 main (argc=<optimized out>, argv=<optimized out>) at main.c:1491
        c = <optimized out>
        r = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--
        tmp = 0x7fffd226be86 ""
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x5595d6eaddc0 "f:cCm:M:b:l:n:N:rRvdDFEVhw:t:u:g:p:P:G:W:o:a:k:s:"
        seed = 1323558878
        rfd = <optimized out>
        __FUNCTION__ = "main"

@adigeo
Copy link
Author

adigeo commented Nov 10, 2020

agp@live02:~/opensips-xs$ sudo gdb opensips /cores/core.3969.opensips.1604904052
Reading symbols from opensips...Reading symbols from /usr/lib/debug/.build-id/46/43585b4d19f3c0d2c850af13d836bb9b7a2b47.debug...done.
done.
[New LWP 3969]
[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 2048'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt full
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
        set = {__val = {0, 93868033126720, 0, 17658287848806282240, 11, 1, 1, 21, 11, 93868033126720, 140728301933920, 
            139831664101909, 0, 93868010474848, 139829540924576, 1604904052}}
        pid = <optimized out>
        tid = <optimized out>
        ret = <optimized out>
#1  0x00007f2d189db535 in __GI_abort () at abort.c:79
        save_stage = 1
        act = {__sigaction_handler = {sa_handler = 0x555f5991d3c8, sa_sigaction = 0x555f5991d3c8}, sa_mask = {__val = {
              93868010477728, 1434, 1410, 93868012983216, 140728301934184, 140728301934188, 93868010478049, 93868010477728, 
              93868012477088, 93868012983240, 17658287848806282240, 93868012477088, 1434, 93868051333008, 93868012983152, 
              93868058528400}}, sa_flags = -596486552, sa_restorer = 0x7ffddc72566c}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x0000555f5952ac9e in build_res_buf_from_sip_res (msg=msg@entry=0x555f5bdaff90, 
    returned_len=returned_len@entry=0x7ffddc725714, sock=<optimized out>, flags=flags@entry=0) at msg_translator.c:2419
        new_len = 1434
        body_delta = <optimized out>
        len = 1437
        new_buf = <optimized out>
        buf = <optimized out>
        offset = 1410
        s_offset = 1408
        body = <optimized out>
        __FUNCTION__ = "build_res_buf_from_sip_res"
#3  0x00007f2c97961a1d in relay_reply (t=0x7f2c9a5d1c50, p_msg=<optimized out>, branch=0, msg_status=200, 
    cancel_bitmap=0x7ffddc725804) at t_reply.c:1282
        relay = 0
        save_clone = 0
        buf = 0x0
        res_len = 0
        relayed_code = 200
        relayed_msg = 0x555f5bdaff90
        bm = {to_tag_val = {s = 0x555f5bdaff90 "\366\376\005", len = 1502290752}}
        totag_retr = 0
        reply_status = <optimized out>
        uas_rb = 0x7f2c9a5d1d50
        cb_s = {s = 0x0, len = 0}
        text = {s = 0x555f5bdaff90 "\366\376\005", len = 1498641304}
        __FUNCTION__ = "relay_reply"
--Type <RET> for more, q to quit, c to continue without paging--
#4  0x00007f2c97963f9d in reply_received (p_msg=0x555f5bdaff90) at t_reply.c:1647
        msg_status = 200
        last_uac_status = <optimized out>
        branch = 0
        reply_status = <optimized out>
        timer = 140728301934784
        cancel_bitmap = 0
        uac = 0x7f2c9a5d1e28
        t = 0x7f2c9a5d1c50
        backup_list = <optimized out>
        has_reply_route = <optimized out>
        old_route_type = <optimized out>
        __FUNCTION__ = "reply_received"
#5  0x0000555f5955c438 in forward_reply (msg=msg@entry=0x555f5bdaff90) at forward.c:499
        new_buf = 0x0
        to = 0x0
        new_len = 0
        mod = 0x555f5999f300
        proto = <optimized out>
        id = 0
        send_sock = <optimized out>
        s = <optimized out>
        len = <optimized out>
        __FUNCTION__ = "forward_reply"
#6  0x0000555f59545027 in receive_msg (
    buf=0x555f598a1aa0 <tcp_current_req> "SIP/2.0 200 OK\r\nVia: SIP/2.0/TCP 85.17.186.23:5060;branch=z9hG4bK8975.f72c5f65.0;i=83cfb6e1\r\nVia: SIP/2.0/TCP 140.242.65.54:5060;rport=13040;received=140.242.65.54;branch=z9hG4bK-343830-6f110b3e813516"..., 
    len=<optimized out>, len@entry=1437, rcv_info=rcv_info@entry=0x7ffddc725a70, existing_context=existing_context@entry=0x0, 
    msg_flags=msg_flags@entry=0) at receive.c:266
        ctx = 0x555f59c239c0
        msg = 0x555f5bdaff90
        start = {tv_sec = 139829544635744, tv_usec = 93868009580396}
        rc = 3
        old_route_type = 4
        tmp = <optimized out>
        in_buff = {
          s = 0x555f598a1aa0 <tcp_current_req> "SIP/2.0 200 OK\r\nVia: SIP/2.0/TCP 85.17.186.23:5060;branch=z9hG4bK8975.f72c5f65.0;i=83cfb6e1\r\nVia: SIP/2.0/TCP 140.242.65.54:5060;rport=13040;received=140.242.65.54;branch=z9hG4bK-343830-6f110b3e813516"..., len = 1437}
--Type <RET> for more, q to quit, c to continue without paging--
        __FUNCTION__ = "receive_msg"
#7  0x0000555f596a9ba5 in tcp_handle_req (_max_msg_chunks=<optimized out>, con=0x7f2c99faa050, 
    req=0x555f598a1aa0 <tcp_current_req>) at net/proto_tcp/tcp_common.h:411
        local_rcv = {src_ip = {af = 2, len = 4, u = {addrl = {3034847057, 0}, addr32 = {3034847057, 0, 0, 0}, addr16 = {5969, 
                46308, 0, 0, 0, 0, 0, 0}, addr = "Q\027\344\264", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {
              addrl = {398070101, 0}, addr32 = {398070101, 0, 0, 0}, addr16 = {4437, 6074, 0, 0, 0, 0, 0, 0}, 
              addr = "U\021\272\027", '\000' <repeats 11 times>}}, src_port = 5060, dst_port = 54037, proto = 2, 
          proto_reserved1 = 510015288, proto_reserved2 = 0, src_su = {s = {sa_family = 2, 
              sa_data = "\023\304Q\027\344\264\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 50195, 
              sin_addr = {s_addr = 3034847057}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, 
              sin6_port = 50195, sin6_flowinfo = 3034847057, 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}}, 
          bind_address = 0x555f5991d370}
        msg_buf = <optimized out>
        msg_len = 1437
        c = 110 'n'
        size = 0
        local_rcv = <optimized out>
        msg_buf = <optimized out>
        msg_len = <optimized out>
        size = <optimized out>
        c = <optimized out>
        __FUNCTION__ = "tcp_handle_req"
        _timeout = <optimized out>
#8  tcp_read_req (con=<optimized out>, bytes_read=0x7ffddc725b30) at net/proto_tcp/proto_tcp.c:1197
        bytes = <optimized out>
        total_bytes = 1437
        req = <optimized out>
        src_su = {s = {sa_family = 23128, sa_data = "r\334\375\177\000\000\000\000\000\000\000\000\000"}, sin = {
            sin_family = 23128, sin_port = 56434, sin_addr = {s_addr = 32765}, sin_zero = "\000\000\000\000\000\000\000"}, 
          sin6 = {sin6_family = 23128, sin6_port = 56434, sin6_flowinfo = 32765, sin6_addr = {__in6_u = {
                __u6_addr8 = "\000\000\000\000\000\000\000\000\200\\\035\232,\177\000", __u6_addr16 = {0, 0, 0, 0, 23680, 
                  39453, 32556, 0}, __u6_addr32 = {0, 0, 2585615488, 32556}}}, sin6_scope_id = 2558135516}}
        dst_su = {s = {sa_family = 22560, sa_data = "\253\230,\177\000\000\273\335iY_U\000"}, sin = {sin_family = 22560, 
            sin_port = 39083, sin_addr = {s_addr = 32556}, sin_zero = "\273\335iY_U\000"}, sin6 = {sin6_family = 22560, 
            sin6_port = 39083, sin6_flowinfo = 32556, sin6_addr = {__in6_u = {
                __u6_addr8 = "\273\335iY_U\000\000`Zr\334\375\177\000", __u6_addr16 = {56763, 22889, 21855, 0, 23136, 56434, 
                  32765, 0}, __u6_addr32 = {1500110267, 21855, 3698481760, 32765}}}, sin6_scope_id = 3698481760}}
        __FUNCTION__ = "tcp_read_req"
--Type <RET> for more, q to quit, c to continue without paging--
#9  0x0000555f59689c7a in handle_io (fm=<optimized out>, idx=idx@entry=0, event_type=event_type@entry=1)
    at net/net_tcp_proc.c:312
        ret = 0
        n = <optimized out>
        con = 0x7f2c99faa050
        s = 305
        rw = <optimized out>
        resp = <optimized out>
        response = {139829538606176, 1}
        __FUNCTION__ = "handle_io"
#10 0x0000555f5968bfb1 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>)
    at net/../io_wait_loop.h:305
        ep_event = {events = 8, data = {ptr = 0x599cb6a000000030, fd = 48, u32 = 48, u64 = 6457236764053471280}}
        curr_time = 96641
        ret = <optimized out>
        n = <optimized out>
        r = 0
        e = <optimized out>
        fd = <optimized out>
        i = <optimized out>
        ret = <optimized out>
        n = <optimized out>
        r = <optimized out>
        i = <optimized out>
        e = <optimized out>
        ep_event = <optimized out>
        fd = <optimized out>
        curr_time = <optimized out>
        __FUNCTION__ = "io_wait_loop_epoll"
#11 tcp_worker_proc_loop () at net/net_tcp_proc.c:422
        __FUNCTION__ = "tcp_worker_proc_loop"
#12 0x0000555f5969c2cb in tcp_start_processes (chd_rank=chd_rank@entry=0x555f5987b5a8 <chd_rank>, 
    startup_done=startup_done@entry=0x0) at net/net_tcp.c:2088
        r = <optimized out>
        n = <optimized out>
        p_id = <optimized out>
        reader_fd = {283, 284}
        si = <optimized out>
        __FUNCTION__ = "tcp_start_processes"
--Type <RET> for more, q to quit, c to continue without paging--
#13 0x0000555f5951a813 in main_loop () at main.c:810
        startup_done = 0x0
        last_check = 0
        rc = <optimized out>
        chd_rank = 6
        startup_done = <optimized out>
        last_check = <optimized out>
        rc = <optimized out>
        __FUNCTION__ = "main_loop"
#14 main (argc=<optimized out>, argv=<optimized out>) at main.c:1491
        c = <optimized out>
        r = <optimized out>
        tmp = 0x7ffddc727e86 ""
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x555f596cedc0 "f:cCm:M:b:l:n:N:rRvdDFEVhw:t:u:g:p:P:G:W:o:a:k:s:"
        seed = 1285683681
        rfd = <optimized out>
        __FUNCTION__ = "main"
(gdb) 

@adigeo
Copy link
Author

adigeo commented Nov 23, 2020

agp@live01:~/opensips-xs$ sudo gdb opensips /cores/core.28082.opensips.1606117700
GNU gdb (Debian 8.2.1-2+b3) 8.2.1
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from opensips...Reading symbols from /usr/lib/debug/.build-id/46/43585b4d19f3c0d2c850af13d836bb9b7a2b47.debug...done.
done.
[New LWP 28082]
[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 2048'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007fde03b1a535 in __GI_abort () at abort.c:79
#2  0x00005624b2dbac33 in qm_free_dbg (qm=<optimized out>, p=0x7fdd85388938, file=<optimized out>, func=<optimized out>, line=<optimized out>) at mem/q_malloc_dyn.h:194
#3  0x00007fdd821e181e in _shm_free (file=<optimized out>, line=<optimized out>, function=<optimized out>, ptr=<optimized out>) at ../../net/../mem/shm_mem.h:448
#4  free_trace_info_shm (param=0x7fdd8518a8a0) at tracer.c:1153
#5  0x00007fdd82149038 in destroy_dlg_callbacks_list (cb=0x7fdd83cede70) at dlg_cb.c:68
#6  0x00007fdd82154331 in free_dlg_dlg (dlg=0x7fdd851707c8) at dlg_hash.c:172
#7  destroy_dlg (dlg=dlg@entry=0x7fdd851707c8) at dlg_hash.c:257
#8  0x00007fdd8215e783 in _unref_dlg (dlg=0x7fdd851707c8, cnt=cnt@entry=1) at dlg_hash.c:1008
#9  0x00007fdd8215ea27 in dialog_cleanup (msg=<optimized out>, param=<optimized out>) at ../tm/../../context.h:193
#10 0x00005624b2d575d1 in exec_post_cb (cb=0x5624b3563710, msg=0x5624b38a8720) at script_cb.c:180
#11 exec_post_req_cb (msg=msg@entry=0x5624b38a8720) at script_cb.c:198
#12 0x00005624b2d20cd9 in receive_msg (
    buf=0x5624b307daa0 <tcp_current_req> "INVITE sip:user3@test.example.com SIP/2.0\r\nVia: SIP/2.0/TCP 192.168.0.231:5060;rport;branch=z9hG4bK931005888\r\nFrom: \"IP DoorPhone\" <sip:user1@test.example.com>;tag=1696682621\r\nTo: <sip:user3@test.muraip"..., len=<optimized out>, len@entry=854, rcv_info=rcv_info@entry=0x7ffc342abcd0, 
    existing_context=existing_context@entry=0x0, msg_flags=msg_flags@entry=0) at receive.c:219
#13 0x00005624b2e85ba5 in tcp_handle_req (_max_msg_chunks=<optimized out>, con=0x7fdd85065888, req=0x5624b307daa0 <tcp_current_req>) at net/proto_tcp/tcp_common.h:411
#14 tcp_read_req (con=<optimized out>, bytes_read=0x7ffc342abd90) at net/proto_tcp/proto_tcp.c:1197
#15 0x00005624b2e65c7a in handle_io (fm=<optimized out>, idx=idx@entry=23, event_type=event_type@entry=1) at net/net_tcp_proc.c:312
#16 0x00005624b2e67fb1 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:305
#17 tcp_worker_proc_loop () at net/net_tcp_proc.c:422
#18 0x00005624b2e782cb in tcp_start_processes (chd_rank=chd_rank@entry=0x5624b30575a8 <chd_rank>, startup_done=startup_done@entry=0x7fdd851489f8) at net/net_tcp.c:2088
#19 0x00005624b2cf6813 in main_loop () at main.c:810
#20 main (argc=<optimized out>, argv=<optimized out>) at main.c:1491
(gdb) bt full
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
        set = {__val = {0, 8150845473757034496, 11, 1, 1, 21, 11, 94715630724784, 140721183701024, 140591522298389, 0, 94715620570928, 94715628130672, 1606117700, 
            94715631231184, 165}}
        pid = <optimized out>
        tid = <optimized out>
        ret = <optimized out>
#1  0x00007fde03b1a535 in __GI_abort () at abort.c:79
        save_stage = 1
        act = {__sigaction_handler = {sa_handler = 0x7fdd821ef5f4, sa_sigaction = 0x7fdd821ef5f4}, sa_mask = {__val = {140589347568160, 1, 94715628130800, 1, 
              94715631011616, 0, 94715619107467, 256, 8150845473757034496, 4, 94715628354096, 94715631011616, 8150845473757034496, 0, 140589373816832, 
              140589399574792}}, sa_flags = -2111900172, sa_restorer = 0x7fdd821efa20 <__FUNCTION__.14404>}
        sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x00005624b2dbac33 in qm_free_dbg (qm=<optimized out>, p=0x7fdd85388938, file=<optimized out>, func=<optimized out>, line=<optimized out>) at mem/q_malloc_dyn.h:194
        f = <optimized out>
        prev = <optimized out>
        next = <optimized out>
        size = <optimized out>
        __FUNCTION__ = "qm_free_dbg"
#3  0x00007fdd821e181e in _shm_free (file=<optimized out>, line=<optimized out>, function=<optimized out>, ptr=<optimized out>) at ../../net/../mem/shm_mem.h:448
No locals.
#4  free_trace_info_shm (param=0x7fdd8518a8a0) at tracer.c:1153
        info = 0x7fdd8518a8a0
        it = 0x7fdd85388938
        next = 0x7fdd856aca10
        __FUNCTION__ = "free_trace_info_shm"
#5  0x00007fdd82149038 in destroy_dlg_callbacks_list (cb=0x7fdd83cede70) at dlg_cb.c:68
        cb_t = 0x7fdd8567d798
        __FUNCTION__ = "destroy_dlg_callbacks_list"
#6  0x00007fdd82154331 in free_dlg_dlg (dlg=0x7fdd851707c8) at dlg_hash.c:172
        dv = <optimized out>
        i = <optimized out>
        dv = <optimized out>
        i = <optimized out>
        __FUNCTION__ = "free_dlg_dlg"
#7  destroy_dlg (dlg=dlg@entry=0x7fdd851707c8) at dlg_hash.c:257
        ret = <optimized out>
        __FUNCTION__ = "destroy_dlg"
#8  0x00007fdd8215e783 in _unref_dlg (dlg=0x7fdd851707c8, cnt=cnt@entry=1) at dlg_hash.c:1008
        d_entry = 0x7fdd84522b18
        __FUNCTION__ = "_unref_dlg"
#9  0x00007fdd8215ea27 in dialog_cleanup (msg=<optimized out>, param=<optimized out>) at ../tm/../../context.h:193
No locals.
#10 0x00005624b2d575d1 in exec_post_cb (cb=0x5624b3563710, msg=0x5624b38a8720) at script_cb.c:180
No locals.
#11 exec_post_req_cb (msg=msg@entry=0x5624b38a8720) at script_cb.c:198
--Type <RET> for more, q to quit, c to continue without paging--
No locals.
#12 0x00005624b2d20cd9 in receive_msg (
    buf=0x5624b307daa0 <tcp_current_req> "INVITE sip:user3@test.example.com SIP/2.0\r\nVia: SIP/2.0/TCP 192.168.0.231:5060;rport;branch=z9hG4bK931005888\r\nFrom: \"IP DoorPhone\" <sip:user1@test.example.com>;tag=1696682621\r\nTo: <sip:user3@test.muraip"..., len=<optimized out>, len@entry=854, rcv_info=rcv_info@entry=0x7ffc342abcd0, 
    existing_context=existing_context@entry=0x0, msg_flags=msg_flags@entry=0) at receive.c:219
        ctx = 0x5624b3827a00
        msg = 0x5624b38a8720
        start = {tv_sec = 140589400942104, tv_usec = 94715619551084}
        rc = <optimized out>
        old_route_type = <optimized out>
        tmp = <optimized out>
        in_buff = {
          s = 0x5624b307daa0 <tcp_current_req> "INVITE sip:user3@test.example.com SIP/2.0\r\nVia: SIP/2.0/TCP 192.168.0.231:5060;rport;branch=z9hG4bK931005888\r\nFrom: \"IP DoorPhone\" <sip:user1@test.example.com>;tag=1696682621\r\nTo: <sip:user3@test.muraip"..., len = 854}
        __FUNCTION__ = "receive_msg"
#13 0x00005624b2e85ba5 in tcp_handle_req (_max_msg_chunks=<optimized out>, con=0x7fdd85065888, req=0x5624b307daa0 <tcp_current_req>) at net/proto_tcp/tcp_common.h:411
        local_rcv = {src_ip = {af = 2, len = 4, u = {addrl = {1466984016, 0}, addr32 = {1466984016, 0, 0, 0}, addr16 = {26192, 22384, 0, 0, 0, 0, 0, 0}, 
              addr = "PfpW", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {3034847057, 0}, addr32 = {3034847057, 0, 0, 0}, addr16 = {5969, 
                46308, 0, 0, 0, 0, 0, 0}, addr = "Q\027\344\264", '\000' <repeats 11 times>}}, src_port = 64065, dst_port = 5060, proto = 2, 
          proto_reserved1 = 185922195, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "\372APfpW\000\000\000\000\000\000\000"}, sin = {sin_family = 2, 
              sin_port = 16890, sin_addr = {s_addr = 1466984016}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 16890, 
              sin6_flowinfo = 1466984016, sin6_addr = {__in6_u = {__u6_addr8 = "\000\000\000\000\000\000\000\000\020\000\000\000$V\000", __u6_addr16 = {0, 0, 0, 0, 16, 
                    0, 22052, 0}, __u6_addr32 = {0, 0, 16, 22052}}}, sin6_scope_id = 1}}, bind_address = 0x5624b3506370}
        msg_buf = <optimized out>
        msg_len = 854
        c = 87 'W'
        size = 0
        local_rcv = <optimized out>
        msg_buf = <optimized out>
        msg_len = <optimized out>
        size = <optimized out>
        c = <optimized out>
        __FUNCTION__ = "tcp_handle_req"
        _timeout = <optimized out>
#14 tcp_read_req (con=<optimized out>, bytes_read=0x7ffc342abd90) at net/proto_tcp/proto_tcp.c:1197
        bytes = <optimized out>
        total_bytes = 854
        req = <optimized out>
        src_su = {s = {sa_family = 0, sa_data = "\000\000\000\000\000\000\005\003\250\202\335\177\000"}, sin = {sin_family = 0, sin_port = 0, sin_addr = {s_addr = 0}, 
            sin_zero = "\005\003\250\202\335\177\000"}, sin6 = {sin6_family = 0, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {
                __u6_addr8 = "\005\003\250\202\335\177\000\000\320\274*4\374\177\000", __u6_addr16 = {773, 33448, 32733, 0, 48336, 13354, 32764, 0}, __u6_addr32 = {
                  2192048901, 32733, 875216080, 32764}}}, sin6_scope_id = 2209198306}}
        dst_su = {s = {sa_family = 904, sa_data = "\000\000\000\000\000\000`\001\256\340\000\000\000"}, sin = {sin_family = 904, sin_port = 0, sin_addr = {s_addr = 0}, 
            sin_zero = "`\001\256\340\000\000\000"}, sin6 = {sin6_family = 904, sin6_port = 0, sin6_flowinfo = 0, sin6_addr = {__in6_u = {
                __u6_addr8 = "`\001\256\340\000\000\000\000\300\274*4\374\177\000", __u6_addr16 = {352, 57518, 0, 0, 48320, 13354, 32764, 0}, __u6_addr32 = {
--Type <RET> for more, q to quit, c to continue without paging--
                  3769500000, 0, 875216064, 32764}}}, sin6_scope_id = 875216064}}
        __FUNCTION__ = "tcp_read_req"
#15 0x00005624b2e65c7a in handle_io (fm=<optimized out>, idx=idx@entry=23, event_type=event_type@entry=1) at net/net_tcp_proc.c:312
        ret = 0
        n = <optimized out>
        con = 0x7fdd85065888
        s = 0
        rw = <optimized out>
        resp = <optimized out>
        response = {140589400208448, 1}
        __FUNCTION__ = "handle_io"
#16 0x00005624b2e67fb1 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:305
        ep_event = {events = 8, data = {ptr = 0xb35b7a2000000030, fd = 48, u32 = 48, u64 = 12924057833527312432}}
        curr_time = 3770
        ret = <optimized out>
        n = <optimized out>
        r = 23
        e = <optimized out>
        fd = <optimized out>
        i = <optimized out>
        ret = <optimized out>
        n = <optimized out>
        r = <optimized out>
        i = <optimized out>
        e = <optimized out>
        ep_event = <optimized out>
        fd = <optimized out>
        curr_time = <optimized out>
        __FUNCTION__ = "io_wait_loop_epoll"
#17 tcp_worker_proc_loop () at net/net_tcp_proc.c:422
        __FUNCTION__ = "tcp_worker_proc_loop"
#18 0x00005624b2e782cb in tcp_start_processes (chd_rank=chd_rank@entry=0x5624b30575a8 <chd_rank>, startup_done=startup_done@entry=0x7fdd851489f8) at net/net_tcp.c:2088
        r = <optimized out>
        n = <optimized out>
        p_id = <optimized out>
        reader_fd = {284, 285}
        si = <optimized out>
        __FUNCTION__ = "tcp_start_processes"
#19 0x00005624b2cf6813 in main_loop () at main.c:810
        startup_done = 0x7fdd851489f8
        last_check = 0
        rc = <optimized out>
        chd_rank = 9
        startup_done = <optimized out>
        last_check = <optimized out>
--Type <RET> for more, q to quit, c to continue without paging--
        rc = <optimized out>
        __FUNCTION__ = "main_loop"
#20 main (argc=<optimized out>, argv=<optimized out>) at main.c:1491
        c = <optimized out>
        r = <optimized out>
        tmp = 0x7ffc342ace86 ""
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x5624b2eaadc0 "f:cCm:M:b:l:n:N:rRvdDFEVhw:t:u:g:p:P:G:W:o:a:k:s:"
        seed = 3843137097
        rfd = <optimized out>
        __FUNCTION__ = "main"

@stale
Copy link

stale bot commented Dec 19, 2020

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.

@stale stale bot added the stale label Dec 19, 2020
@bogdan-iancu bogdan-iancu self-assigned this Jan 8, 2021
@stale stale bot removed the stale label Jan 8, 2021
@OpenSIPS OpenSIPS deleted a comment from adigeo Jan 8, 2021
@OpenSIPS OpenSIPS deleted a comment from adigeo Jan 8, 2021
@OpenSIPS OpenSIPS deleted a comment from adigeo Jan 8, 2021
@OpenSIPS OpenSIPS deleted a comment from adigeo Jan 8, 2021
@OpenSIPS OpenSIPS deleted a comment from adigeo Jan 8, 2021
@OpenSIPS OpenSIPS deleted a comment from adigeo Jan 8, 2021
@OpenSIPS OpenSIPS deleted a comment from adigeo Jan 8, 2021
@bogdan-iancu bogdan-iancu added this to the 3.1.2 milestone Jan 8, 2021
@bogdan-iancu
Copy link
Member

@adigeo , I did some cleanup here, I removed all the backtraces showing shutdown crashes, as not relevant (traces showing the shutdown_opensips frame)

@bogdan-iancu
Copy link
Member

Now, 90% of the crashes are triggered from an abort in build_res_buf_from_sip_res(), failing to properly apply the lumps to the reply msg.
Do you have such a corefile and its binary, so we can investigate (under gdb) the chain of lumps and the resulting buffer ?

@stale
Copy link

stale bot commented Jul 21, 2021

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.

@stale stale bot added the stale label Jul 21, 2021
@github-actions
Copy link

Marking as closed due to lack of progress for more than 30 days. If this issue is still relevant, please re-open it with additional details.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants