search

OpenSIPS / opensips

OpenSIPS is a GPL implementation of a multi-functionality SIP Server that targets to deliver a high-level technical solution (performance, security and quality) to be used in professional SIP server platforms.
https://opensips.org
Other
1.25k stars 575 forks source link

[CRASH] 3.1 segfault in TLS #1799

Closed danpascu closed 4 years ago

danpascu commented 5 years ago

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, CC_O0, FAST_LOCK-ADAPTIVE_WAIT, DBG_LOCK
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: 6884b3d17
main.c compiled on  with gcc 8

Crash Core Dump

(gdb) bt
#0  EVP_DecryptUpdate (inl=16, in=0x7f901d14bd80 "\217\034|G\277\332:7o|\220\373\071\001\036\063xq\232)\234\225(\214\005o}:\370\230\330\n\341\212\350\330/\274\325\020\345\206\v\220\071", outl=0x7ffdba100a34, 
    out=0x7f901d14bd90 "xq\232)\234\225(\214\005o}:\370\230\330\n\341\212\350\330/\274\325\020\345\206\v\220\071", ctx=0x7f901d14be38) at ../crypto/evp/evp_enc.c:455
#1  EVP_DecryptUpdate (ctx=0x7f901d14be38, out=0x7f901d14bd90 "xq\232)\234\225(\214\005o}:\370\230\330\n\341\212\350\330/\274\325\020\345\206\v\220\071", outl=0x7ffdba100a34, 
    in=0x7f901d14bd80 "\217\034|G\277\332:7o|\220\373\071\001\036\063xq\232)\234\225(\214\005o}:\370\230\330\n\341\212\350\330/\274\325\020\345\206\v\220\071", inl=16) at ../crypto/evp/evp_enc.c:443
#2  0x00007f901cb760f3 in ctr_df (in3len=16, in3=0x7f901d14c5b8 "@W\375<\220\177", in2len=0, in2=0x0, in1len=<optimized out>, 
    in1=0x7f901e2f4ff8 "\f\017\357@A3\217\207\360)-X\372\357\355GL\036\330\177^j,\311\376Q=\266\333:\322", <incomplete sequence \356>, ctr=0x7f901d14bd18) at ../crypto/rand/drbg_ctr.c:210
#3  ctr_update (drbg=0x7f901d14bc70, in1=0x7f901e2f4ff8 "\f\017\357@A3\217\207\360)-X\372\357\355GL\036\330\177^j,\311\376Q=\266\333:\322", <incomplete sequence \356>, in1len=32, in2=0x7f901d14c5b8 "@W\375<\220\177", 
    in2len=<optimized out>, nonce=nonce@entry=0x0, noncelen=<optimized out>) at ../crypto/rand/drbg_ctr.c:264
#4  0x00007f901cb76423 in drbg_ctr_reseed (adinlen=<optimized out>, adin=<optimized out>, entropylen=<optimized out>, entropy=<optimized out>, drbg=<optimized out>) at ../crypto/rand/drbg_ctr.c:304
#5  drbg_ctr_reseed (drbg=<optimized out>, entropy=<optimized out>, entropylen=<optimized out>, adin=<optimized out>, adinlen=<optimized out>) at ../crypto/rand/drbg_ctr.c:298
#6  0x00007f901cb76dd1 in RAND_DRBG_reseed (drbg=drbg@entry=0x7f901d14bc70, adin=adin@entry=0x7f901d14c5b8 "@W\375<\220\177", adinlen=adinlen@entry=16, prediction_resistance=prediction_resistance@entry=0)
    at ../crypto/rand/drbg_lib.c:450
#7  0x00007f901cb7726a in RAND_DRBG_generate (drbg=drbg@entry=0x7f901d14bc70, out=out@entry=0x7f901e1f8650 "", outlen=outlen@entry=32, prediction_resistance=prediction_resistance@entry=0, adin=0x7f901d14c5b8 "@W\375<\220\177", 
    adinlen=adinlen@entry=16) at ../crypto/rand/drbg_lib.c:630
#8  0x00007f901cb77481 in RAND_DRBG_bytes (drbg=0x7f901d14bc70, out=0x7f901e1f8650 "", outlen=32) at ../crypto/rand/drbg_lib.c:679
#9  0x00007f901ccdd6fd in ssl_fill_hello_random (s=s@entry=0x7f901e2117a8, server=server@entry=1, result=0x7f901e1f8650 "", len=len@entry=32, dgrd=DOWNGRADE_TO_1_2) at ../ssl/s3_lib.c:4589
#10 0x00007f901cd0ea99 in tls_early_post_process_client_hello (s=0x7f901e2117a8) at ../ssl/statem/statem_srvr.c:1902
#11 tls_post_process_client_hello (s=0x7f901e2117a8, wst=<optimized out>) at ../ssl/statem/statem_srvr.c:2226
#12 0x00007f901ccfe55b in read_state_machine (s=0x7f901e2117a8) at ../ssl/statem/statem.c:664
#13 state_machine (s=0x7f901e2117a8, server=1) at ../ssl/statem/statem.c:434
#14 0x00007f901ccea264 in SSL_do_handshake (s=0x7f901e2117a8) at ../ssl/ssl_lib.c:3599
#15 0x00007f901cd6702a in tls_accept (c=0x7f901e1fd250, poll_events=0x0) at ../tls_mgm/tls_conn_server.h:270
#16 0x00007f901cd685c7 in tls_fix_read_conn (c=0x7f901e1fd250, t_dst=0x0) at ../tls_mgm/tls_conn_server.h:529
#17 0x00007f901cd6c39c in tls_read_req (con=0x7f901e1fd250, bytes_read=0x7ffdba100e6c) at proto_tls.c:546
#18 0x00005580191c1194 in handle_io (fm=0x7f90191f4bd0, idx=1, event_type=1) at net/net_tcp_proc.c:301
#19 0x00005580191bf842 in io_wait_loop_epoll (h=0x5580192e0880 <_worker_io>, t=2, repeat=0) at net/../io_wait_loop.h:280
#20 0x00005580191c1a6c in tcp_worker_proc_loop () at net/net_tcp_proc.c:411
#21 0x00005580191d1fdb in tcp_start_processes (chd_rank=0x5580192a9f3c <chd_rank>, startup_done=0x0) at net/net_tcp.c:2076
#22 0x00005580190fc4f0 in main_loop () at main.c:801
#23 0x00005580190ff86c in main (argc=15, argv=0x7ffdba1011b8) at main.c:1480
(gdb) frame 0
#0  EVP_DecryptUpdate (inl=16, in=0x7f901d14bd80 "\217\034|G\277\332:7o|\220\373\071\001\036\063xq\232)\234\225(\214\005o}:\370\230\330\n\341\212\350\330/\274\325\020\345\206\v\220\071", outl=0x7ffdba100a34, 
    out=0x7f901d14bd90 "xq\232)\234\225(\214\005o}:\370\230\330\n\341\212\350\330/\274\325\020\345\206\v\220\071", ctx=0x7f901d14be38) at ../crypto/evp/evp_enc.c:455
455     ../crypto/evp/evp_enc.c: No such file or directory.
(gdb) print ctx
$7 = (EVP_CIPHER_CTX *) 0x7f901d14be38
(gdb) print ctx->cipher
$8 = (const EVP_CIPHER *) 0x7f901e2f8058
(gdb) print ctx->cipher->block_size 
$9 = 1279593435
(gdb) print *ctx->cipher
$10 = {nid = -1022239884, block_size = 1279593435, key_len = 1806233390, iv_len = 1994392236, flags = 13227913398160867695, init = 0x4f617c2e4b125fe0, do_cipher = 0xc0c0c0c0c0c0c0c0, cleanup = 0xabcdefedabcdefed, 
  ctx_size = 505481600, set_asn1_parameters = 0x500000000, get_asn1_parameters = 0x20, ctrl = 0x7f901d14be08, app_data = 0x20}
(gdb) print /x *ctx->cipher
$11 = {nid = 0xc311db74, block_size = 0x4c450bdb, key_len = 0x6ba8ef2e, iv_len = 0x76e002ac, flags = 0xb792fd26b102416f, init = 0x4f617c2e4b125fe0, do_cipher = 0xc0c0c0c0c0c0c0c0, cleanup = 0xabcdefedabcdefed, ctx_size = 0x1e210980, 
  set_asn1_parameters = 0x500000000, get_asn1_parameters = 0x20, ctrl = 0x7f901d14be08, app_data = 0x20}
(gdb)

it crahses at line 455 in libssl in crypto/evp/evp_enc.c which reads:

   443  int EVP_DecryptUpdate(EVP_CIPHER_CTX *ctx, unsigned char *out, int *outl,
   444                        const unsigned char *in, int inl)
   445  {
   446      int fix_len, cmpl = inl;
   447      unsigned int b;
   448  
   449      /* Prevent accidental use of encryption context when decrypting */
   450      if (ctx->encrypt) {
   451          EVPerr(EVP_F_EVP_DECRYPTUPDATE, EVP_R_INVALID_OPERATION);
   452          return 0;
   453      }
   454  
   455      b = ctx->cipher->block_size;
   456  
   457      if (EVP_CIPHER_CTX_test_flags(ctx, EVP_CIPH_FLAG_LENGTH_BITS))
   458          cmpl = (cmpl + 7) / 8;
   459

The segfault is a bit weird, because while ctx->cipher->block_size contains an absurdly high value suggesting that ctx->cipher is corrupted, it can be accessed just fine in the debugger, i.e. there doesn't seem to be an illegal memory access on line 455, unless there was in this process at the time, but then some other process overwrote ctx->cipher during shutdown.

Also the value for cipher->do_cipher and cipher->cleanup look suspiciously like memory boundary markers from qmalloc, but I've seen no memory corruption being reported by qmalloc despite the fact that I run with Q_MALLOC_DBG.

To Reproduce

Wish I knew.

Relevant System Logs

While this particular process crashed, another process reported some errors about some resource being temporarily unavailable in TLS code:

Aug 12 02:33:34 node15 ./opensips[24070]: CRITICAL:core:sig_usr: segfault in process pid: 24070, id: 13
Aug 12 02:33:34 node15 ./opensips[24069]: ERROR:proto_tls:tls_accept: New TLS connection from 1.2.3.4:34454 failed to accept
Aug 12 02:33:34 node15 ./opensips[24069]: ERROR:proto_tls:tls_accept: TLS error: (ret=-1, err=1, errno=11/Resource temporarily unavailable):
Aug 12 02:33:34 node15 ./opensips[24069]: ERROR:proto_tls:tls_print_errstack: TLS errstack: error:24067044:random number generator:rand_pool_add:internal error
Aug 12 02:33:34 node15 ./opensips[24069]: ERROR:proto_tls:tls_read_req: failed to do pre-tls reading
Aug 12 02:33:36 node15 ./opensips[24055]: INFO:core:handle_sigs: child process 24070 exited by a signal 11

OS/environment information

danpascu commented 5 years ago

Some additional errors I noticed in the logs during shutdown:

Aug 12 02:33:36 node15 ./opensips[24055]: ERROR:proto_tls:tls_conn_shutdown: something wrong in SSL: 1, 0, Success
Aug 12 02:33:36 node15 ./opensips[24055]: ERROR:proto_tls:tls_print_errstack: TLS errstack: error:140E0197:SSL routines:SSL_shutdown:shutdown while in init
danpascu commented 5 years ago

I just got another crash. While it ends up crashing in a different function, it originates with the same call to SSL_do_handshake() and the cause it the same: the SSL context is completely overwritten with NULL bytes:

(gdb) bt
#0  aesni_ecb_encrypt () at crypto/aes/aesni-x86_64.s:624
#1  0x00007f77b1b9f917 in aesni_ecb_cipher (len=16, in=0x7f77b21b3d58 ">\\\224\360\305R\224'\027\205\273xບ\221DRBG\200", out=0x7f77b33d6c28 "", ctx=0x7f77b21b3e38) at ../crypto/evp/e_aes.c:319
#2  aesni_ecb_cipher (ctx=0x7f77b21b3e38, out=0x7f77b33d6c28 "", in=0x7f77b21b3d58 ">\\\224\360\305R\224'\027\205\273xບ\221DRBG\200", len=16) at ../crypto/evp/e_aes.c:311
#3  0x00007f77b1bab533 in evp_EncryptDecryptUpdate (ctx=0x7f77b21b3e38, out=0x7f77b33d6c28 "", outl=0x7ffc7ceac894, in=0x7f77b21b3d58 ">\\\224\360\305R\224'\027\205\273xບ\221DRBG\200", inl=16) at ../crypto/evp/evp_enc.c:333
#4  0x00007f77b1bde30f in drbg_ctr_generate (drbg=0x7f77b21b3c70, out=0x7f77b33d6c28 "", outlen=32, adin=0x0, adinlen=0) at ../crypto/rand/drbg_ctr.c:340
#5  0x00007f77b1bdf1fb in RAND_DRBG_generate (drbg=drbg@entry=0x7f77b21b3c70, out=out@entry=0x7f77b33d6c28 "", outlen=outlen@entry=32, prediction_resistance=prediction_resistance@entry=0, adin=0x0, adinlen=0, adinlen@entry=16)
    at ../crypto/rand/drbg_lib.c:638
#6  0x00007f77b1bdf481 in RAND_DRBG_bytes (drbg=0x7f77b21b3c70, out=0x7f77b33d6c28 "", outlen=32) at ../crypto/rand/drbg_lib.c:679
#7  0x00007f77b1d456fd in ssl_fill_hello_random (s=s@entry=0x7f77b32e7870, server=server@entry=1, result=0x7f77b33d6c28 "", len=len@entry=32, dgrd=DOWNGRADE_TO_1_2) at ../ssl/s3_lib.c:4589
#8  0x00007f77b1d76a99 in tls_early_post_process_client_hello (s=0x7f77b32e7870) at ../ssl/statem/statem_srvr.c:1902
#9  tls_post_process_client_hello (s=0x7f77b32e7870, wst=<optimized out>) at ../ssl/statem/statem_srvr.c:2226
#10 0x00007f77b1d6655b in read_state_machine (s=0x7f77b32e7870) at ../ssl/statem/statem.c:664
#11 state_machine (s=0x7f77b32e7870, server=1) at ../ssl/statem/statem.c:434
#12 0x00007f77b1d52264 in SSL_do_handshake (s=0x7f77b32e7870) at ../ssl/ssl_lib.c:3599
#13 0x00007f77b1dcf02a in tls_accept (c=0x7f77b33277a8, poll_events=0x0) at ../tls_mgm/tls_conn_server.h:270
#14 0x00007f77b1dd05c7 in tls_fix_read_conn (c=0x7f77b33277a8, t_dst=0x0) at ../tls_mgm/tls_conn_server.h:529
#15 0x00007f77b1dd439c in tls_read_req (con=0x7f77b33277a8, bytes_read=0x7ffc7ceacc6c) at proto_tls.c:546
#16 0x000055e4206b7194 in handle_io (fm=0x7f77ae25cbd0, idx=1, event_type=1) at net/net_tcp_proc.c:301
#17 0x000055e4206b5842 in io_wait_loop_epoll (h=0x55e4207d6880 <_worker_io>, t=2, repeat=0) at net/../io_wait_loop.h:280
#18 0x000055e4206b7a6c in tcp_worker_proc_loop () at net/net_tcp_proc.c:411
#19 0x000055e4206c7fdb in tcp_start_processes (chd_rank=0x55e42079ff3c <chd_rank>, startup_done=0x0) at net/net_tcp.c:2076
#20 0x000055e4205f24f0 in main_loop () at main.c:801
#21 0x000055e4205f586c in main (argc=15, argv=0x7ffc7ceacfb8) at main.c:1480
(gdb) print ctx
No symbol "ctx" in current context.
(gdb) frame 1
#1  0x00007f77b1b9f917 in aesni_ecb_cipher (len=16, in=0x7f77b21b3d58 ">\\\224\360\305R\224'\027\205\273xບ\221DRBG\200", out=0x7f77b33d6c28 "", ctx=0x7f77b21b3e38) at ../crypto/evp/e_aes.c:319
319     ../crypto/evp/e_aes.c: No such file or directory.
(gdb) print ctx
$1 = (EVP_CIPHER_CTX *) 0x7f77b21b3e38
(gdb) print *ctx
$2 = {cipher = 0x0, engine = 0x0, encrypt = 0, buf_len = 0, oiv = '\000' <repeats 15 times>, iv = '\000' <repeats 15 times>, buf = '\000' <repeats 31 times>, num = 0, app_data = 0x0, key_len = 0, flags = 0, cipher_data = 0x0, 
  final_used = 0, block_mask = 0, final = '\000' <repeats 31 times>}
(gdb)
danpascu commented 5 years ago

Got another one. This time q_malloc complained in syslog with:

Aug 13 20:38:52 node15 ./opensips[869]: CRITICAL:core:qm_free_dbg: freeing already freed pointer, first free: ../crypto/evp/evp_enc.c: os_free(32) - aborting
Aug 13 20:38:55 node15 ./opensips[855]: INFO:core:handle_sigs: child process 869 exited by a signal 6

and the back trace was:

(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007f82e83aa535 in __GI_abort () at abort.c:79
#2  0x000055eb02b5bc49 in qm_free_dbg (qm=0x7f82c8328000, p=0x7f82c86ef618, file=0x7f82c81b046f "../crypto/evp/evp_enc.c", func=0x7f82c7f2ff10 <__FUNCTION__.29024> "os_free", line=32) at mem/q_malloc_dyn.h:204
#3  0x00007f82c7f1ac7b in _shm_free (ptr=0x7f82c86ef618, file=0x7f82c81b046f "../crypto/evp/evp_enc.c", function=0x7f82c7f2ff10 <__FUNCTION__.29024> "os_free", line=32) at ../../mem/shm_mem.h:448
#4  0x00007f82c7f1e46d in os_free (ptr=0x7f82c86ef618, file=0x7f82c81b046f "../crypto/evp/evp_enc.c", line=32) at tls.h:114
#5  0x00007f82c80e32c9 in EVP_CIPHER_CTX_reset (c=0x7f82c86ebe38) at ../crypto/evp/evp_enc.c:32
#6  EVP_CIPHER_CTX_reset (c=0x7f82c86ebe38) at ../crypto/evp/evp_enc.c:21
#7  0x00007f82c80e3f51 in EVP_CipherInit_ex (ctx=0x7f82c86ebe38, cipher=0x7f82c821ede0 <aesni_256_ecb>, impl=impl@entry=0x0, 
    key=key@entry=0x7f82c86ebd80 "M\334u\323{\353\326\330:\r\032S\236Y\003\070\345\347\203ǖ\303Z\255t\374\alJh\017VӟU\036$\024h ڦ\001-_\223\254\217", iv=iv@entry=0x0, enc=<optimized out>, enc@entry=1) at ../crypto/evp/evp_enc.c:89
#8  0x00007f82c8116091 in ctr_df (in3len=0, in3=0x0, in2len=0, in2=0x0, in1len=<optimized out>, in1=0x7f82c86ec5b8 "@\327V\350\202\177", ctr=0x7f82c86ebd18) at ../crypto/rand/drbg_ctr.c:203
#9  ctr_update (drbg=0x7f82c86ebc70, in1=in1@entry=0x7f82c86ec5b8 "@\327V\350\202\177", in1len=in1len@entry=32, in2=in2@entry=0x0, in2len=in2len@entry=0, nonce=nonce@entry=0x0, noncelen=<optimized out>)
    at ../crypto/rand/drbg_ctr.c:264
#10 0x00007f82c81163ad in drbg_ctr_generate (drbg=0x7f82c86ebc70, out=0x7f82c9878c70 "", outlen=32, adin=0x7f82c86ec5b8 "@\327V\350\202\177", adinlen=32) at ../crypto/rand/drbg_ctr.c:316
#11 0x00007f82c81171fb in RAND_DRBG_generate (drbg=drbg@entry=0x7f82c86ebc70, out=out@entry=0x7f82c9878c70 "", outlen=outlen@entry=32, prediction_resistance=prediction_resistance@entry=0, adin=0x7f82c86ec5b8 "@\327V\350\202\177", 
    adinlen=adinlen@entry=32) at ../crypto/rand/drbg_lib.c:638
#12 0x00007f82c8117481 in RAND_DRBG_bytes (drbg=0x7f82c86ebc70, out=0x7f82c9878c70 "", outlen=32) at ../crypto/rand/drbg_lib.c:679
#13 0x00007f82c827d6fd in ssl_fill_hello_random (s=s@entry=0x7f82c984e478, server=server@entry=1, result=0x7f82c9878c70 "", len=len@entry=32, dgrd=DOWNGRADE_TO_1_2) at ../ssl/s3_lib.c:4589
#14 0x00007f82c82aea99 in tls_early_post_process_client_hello (s=0x7f82c984e478) at ../ssl/statem/statem_srvr.c:1902
#15 tls_post_process_client_hello (s=0x7f82c984e478, wst=<optimized out>) at ../ssl/statem/statem_srvr.c:2226
#16 0x00007f82c829e55b in read_state_machine (s=0x7f82c984e478) at ../ssl/statem/statem.c:664
#17 state_machine (s=0x7f82c984e478, server=1) at ../ssl/statem/statem.c:434
#18 0x00007f82c828a264 in SSL_do_handshake (s=0x7f82c984e478) at ../ssl/ssl_lib.c:3599
#19 0x00007f82c830702a in tls_accept (c=0x7f82c98633a0, poll_events=0x0) at ../tls_mgm/tls_conn_server.h:270
#20 0x00007f82c83085c7 in tls_fix_read_conn (c=0x7f82c98633a0, t_dst=0x0) at ../tls_mgm/tls_conn_server.h:529
#21 0x00007f82c830c39c in tls_read_req (con=0x7f82c98633a0, bytes_read=0x7ffd659a791c) at proto_tls.c:546
#22 0x000055eb02bf8194 in handle_io (fm=0x7f82c4793088, idx=1, event_type=1) at net/net_tcp_proc.c:301
#23 0x000055eb02bf6842 in io_wait_loop_epoll (h=0x55eb02d17880 <_worker_io>, t=2, repeat=0) at net/../io_wait_loop.h:280
#24 0x000055eb02bf8a6c in tcp_worker_proc_loop () at net/net_tcp_proc.c:411
#25 0x000055eb02c08fdb in tcp_start_processes (chd_rank=0x55eb02ce0f3c <chd_rank>, startup_done=0x0) at net/net_tcp.c:2076
#26 0x000055eb02b334f0 in main_loop () at main.c:801
#27 0x000055eb02b3686c in main (argc=15, argv=0x7ffd659a7c68) at main.c:1480
(gdb)
danpascu commented 5 years ago

I can consistently crash opensips by running the attached script. You'll need python 2.7 and python-gnutls + twisted for it to work:

test-opensips.txt

Just run the script with the proxy IP/hostname as argument. If port is not 5061 see the script's --help message about how to change running parameters. The script has 4 modes of operation, but regardless which one is used, it always crashes opensips, so you can just go with the default.

With it I get multiple core dumps from opensips at one time. They all seem to point to the same problem: the SSL context gets corrupted (i.e. something writes over it with garbage).

3 processes crashed with this backtrace:

(gdb) bt
#0  aesni_ecb_encrypt () at crypto/aes/aesni-x86_64.s:624
#1  0x00007f454e41f917 in aesni_ecb_cipher (len=16, in=0x7f454ea33d58 "\332͏DM\336J\223Ą\"\256\207U\252\255\300\nB\002", out=0x7f454fa06f30 "", ctx=0x7f454ea33e38) at ../crypto/evp/e_aes.c:319
#2  aesni_ecb_cipher (ctx=0x7f454ea33e38, out=0x7f454fa06f30 "", in=0x7f454ea33d58 "\332͏DM\336J\223Ą\"\256\207U\252\255\300\nB\002", len=16) at ../crypto/evp/e_aes.c:311
#3  0x00007f454e42b533 in evp_EncryptDecryptUpdate (ctx=0x7f454ea33e38, out=0x7f454fa06f30 "", outl=0x7ffed6145cc4, in=0x7f454ea33d58 "\332͏DM\336J\223Ą\"\256\207U\252\255\300\nB\002", inl=16) at ../crypto/evp/evp_enc.c:333
#4  0x00007f454e45e30f in drbg_ctr_generate (drbg=0x7f454ea33c70, out=0x7f454fa06f30 "", outlen=32, adin=0x0, adinlen=0) at ../crypto/rand/drbg_ctr.c:340
#5  0x00007f454e45f1fb in RAND_DRBG_generate (drbg=drbg@entry=0x7f454ea33c70, out=out@entry=0x7f454fa06f30 "", outlen=outlen@entry=32, prediction_resistance=prediction_resistance@entry=0, adin=0x0, adinlen=adinlen@entry=0)
    at ../crypto/rand/drbg_lib.c:638
#6  0x00007f454e45f481 in RAND_DRBG_bytes (drbg=0x7f454ea33c70, out=0x7f454fa06f30 "", outlen=32) at ../crypto/rand/drbg_lib.c:679
#7  0x00007f454e5c56fd in ssl_fill_hello_random (s=s@entry=0x7f454fb05b00, server=server@entry=1, result=0x7f454fa06f30 "", len=len@entry=32, dgrd=DOWNGRADE_NONE) at ../ssl/s3_lib.c:4589
#8  0x00007f454e5f6a99 in tls_early_post_process_client_hello (s=0x7f454fb05b00) at ../ssl/statem/statem_srvr.c:1902
#9  tls_post_process_client_hello (s=0x7f454fb05b00, wst=<optimized out>) at ../ssl/statem/statem_srvr.c:2226
#10 0x00007f454e5e655b in read_state_machine (s=0x7f454fb05b00) at ../ssl/statem/statem.c:664
#11 state_machine (s=0x7f454fb05b00, server=1) at ../ssl/statem/statem.c:434
#12 0x00007f454e5d2264 in SSL_do_handshake (s=0x7f454fb05b00) at ../ssl/ssl_lib.c:3599
#13 0x00007f454e64f02a in tls_accept (c=0x7f454faccf38, poll_events=0x0) at ../tls_mgm/tls_conn_server.h:270
#14 0x00007f454e6505c7 in tls_fix_read_conn (c=0x7f454faccf38, t_dst=0x0) at ../tls_mgm/tls_conn_server.h:529
#15 0x00007f454e65439c in tls_read_req (con=0x7f454faccf38, bytes_read=0x7ffed614609c) at proto_tls.c:546
#16 0x000055d52eb3dd09 in handle_io (fm=0x7f454ab04bd0, idx=1, event_type=1) at net/net_tcp_proc.c:301
#17 0x000055d52eb3c3b7 in io_wait_loop_epoll (h=0x55d52ec5da60 <_worker_io>, t=2, repeat=0) at net/../io_wait_loop.h:280
#18 0x000055d52eb3e5e1 in tcp_worker_proc_loop () at net/net_tcp_proc.c:411
#19 0x000055d52eb4eb50 in tcp_start_processes (chd_rank=0x55d52ec26f5c <chd_rank>, startup_done=0x0) at net/net_tcp.c:2076
#20 0x000055d52ea79b68 in main_loop () at main.c:804
#21 0x000055d52ea7cee4 in main (argc=15, argv=0x7ffed61463e8) at main.c:1483
(gdb) frame 1
#1  0x00007f454e41f917 in aesni_ecb_cipher (len=16, in=0x7f454ea33d58 "\332͏DM\336J\223Ą\"\256\207U\252\255\300\nB\002", out=0x7f454fa06f30 "", ctx=0x7f454ea33e38) at ../crypto/evp/e_aes.c:319
319         aesni_ecb_encrypt(in, out, len, &EVP_C_DATA(EVP_AES_KEY,ctx)->ks.ks,
(gdb) print ctx
$1 = (EVP_CIPHER_CTX *) 0x7f454ea33e38
(gdb) print *ctx
$2 = {cipher = 0x7f454e566de0 <aesni_256_ecb>, engine = 0x0, encrypt = 1, buf_len = 0, oiv = '\000' <repeats 15 times>, iv = '\000' <repeats 15 times>, buf = '\000' <repeats 31 times>, num = 0, app_data = 0x0, key_len = 0, flags = 0, 
  cipher_data = 0x0, final_used = 0, block_mask = 0, final = '\000' <repeats 31 times>}
(gdb)

while the 4th one had this backtrace:

(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007f456e6f2535 in __GI_abort () at abort.c:79
#2  0x000055d52eaa0e63 in qm_free_dbg (qm=0x7f454e670000, p=0x7f454fccd188, file=0x7f454e4f846f "../crypto/evp/evp_enc.c", func=0x7f454e29ff10 <__FUNCTION__.29026> "os_free", line=32) at mem/q_malloc_dyn.h:204
#3  0x00007f454e28ab6b in _shm_free (ptr=0x7f454fccd188, file=0x7f454e4f846f "../crypto/evp/evp_enc.c", function=0x7f454e29ff10 <__FUNCTION__.29026> "os_free", line=32) at ../../mem/shm_mem.h:448
#4  0x00007f454e28e35d in os_free (ptr=0x7f454fccd188, file=0x7f454e4f846f "../crypto/evp/evp_enc.c", line=32) at tls.h:114
#5  0x00007f454e42b2c9 in EVP_CIPHER_CTX_reset (c=0x7f454ea33e38) at ../crypto/evp/evp_enc.c:32
#6  EVP_CIPHER_CTX_reset (c=0x7f454ea33e38) at ../crypto/evp/evp_enc.c:21
#7  0x00007f454e42bf51 in EVP_CipherInit_ex (ctx=0x7f454ea33e38, cipher=0x7f454e566de0 <aesni_256_ecb>, impl=impl@entry=0x0, 
    key=key@entry=0x7f454ea33d80 "ɀ1\202\322\"\202+\314\\\340\253\005\003\201\223F}^\350\rp,\240\324\351w\377\374\305\370\373`o\036d\212)G\211\346f\273\325\364\022\035\221", iv=iv@entry=0x0, enc=<optimized out>, enc@entry=1)
    at ../crypto/evp/evp_enc.c:89
#8  0x00007f454e45e091 in ctr_df (in3len=0, in3=0x0, in2len=0, in2=0x0, in1len=<optimized out>, in1=0x7f454ea345b8 "\200\253\222nE\177", ctr=0x7f454ea33d18) at ../crypto/rand/drbg_ctr.c:203
#9  ctr_update (drbg=0x7f454ea33c70, in1=in1@entry=0x7f454ea345b8 "\200\253\222nE\177", in1len=in1len@entry=16, in2=in2@entry=0x0, in2len=in2len@entry=0, nonce=nonce@entry=0x0, noncelen=<optimized out>)
    at ../crypto/rand/drbg_ctr.c:264
#10 0x00007f454e45e3ad in drbg_ctr_generate (drbg=0x7f454ea33c70, out=0x7f454fcd36c8 "", outlen=32, adin=0x7f454ea345b8 "\200\253\222nE\177", adinlen=16) at ../crypto/rand/drbg_ctr.c:316
#11 0x00007f454e45f1fb in RAND_DRBG_generate (drbg=drbg@entry=0x7f454ea33c70, out=out@entry=0x7f454fcd36c8 "", outlen=outlen@entry=32, prediction_resistance=prediction_resistance@entry=0, adin=0x7f454ea345b8 "\200\253\222nE\177", 
    adinlen=adinlen@entry=16) at ../crypto/rand/drbg_lib.c:638
#12 0x00007f454e45f481 in RAND_DRBG_bytes (drbg=0x7f454ea33c70, out=0x7f454fcd36c8 "", outlen=32) at ../crypto/rand/drbg_lib.c:679
#13 0x00007f454e46ec60 in RSA_padding_add_PKCS1_PSS_mgf1 (rsa=rsa@entry=0x7f454ea53b78, EM=0x7f454fcd3998 "", 
    mHash=mHash@entry=0x7ffed6145c70 "\324@m\241\f\361\274\021]\243e-etF\217˦=\006\264&%\334h\203\003\r\334\377\276,0l\315OE\177", Hash=0x7f454e56a040 <sha256_md>, mgf1Hash=0x7f454e56a040 <sha256_md>, sLen=32)
    at ../crypto/rsa/rsa_pss.c:203
#14 0x00007f454e46e149 in pkey_rsa_sign (ctx=0x7f454fcce938, sig=0x7f454fcd5af0 "", siglen=0x7ffed6145d20, tbs=0x7ffed6145c70 "\324@m\241\f\361\274\021]\243e-etF\217˦=\006\264&%\334h\203\003\r\334\377\276,0l\315OE\177", tbslen=32)
    at ../crypto/rsa/rsa_pmeth.c:171
#15 0x00007f454e42ee4c in EVP_DigestSignFinal (ctx=0x7f454fb82eb0, sigret=0x7f454fcd5af0 "", siglen=0x7ffed6145d20) at ../crypto/evp/m_sigver.c:148
#16 0x00007f454e5ef591 in tls_construct_cert_verify (s=0x7f454fb07a30, pkt=0x7ffed6145e70) at ../ssl/statem/statem_lib.c:297
#17 0x00007f454e5e633f in write_state_machine (s=0x7f454fb07a30) at ../ssl/statem/statem.c:843
#18 state_machine (s=0x7f454fb07a30, server=1) at ../ssl/statem/statem.c:443
#19 0x00007f454e5d2264 in SSL_do_handshake (s=0x7f454fb07a30) at ../ssl/ssl_lib.c:3599
#20 0x00007f454e64f02a in tls_accept (c=0x7f454fb69720, poll_events=0x0) at ../tls_mgm/tls_conn_server.h:270
#21 0x00007f454e6505c7 in tls_fix_read_conn (c=0x7f454fb69720, t_dst=0x0) at ../tls_mgm/tls_conn_server.h:529
#22 0x00007f454e65439c in tls_read_req (con=0x7f454fb69720, bytes_read=0x7ffed614609c) at proto_tls.c:546
#23 0x000055d52eb3dd09 in handle_io (fm=0x7f454ab04bb8, idx=2, event_type=1) at net/net_tcp_proc.c:301
#24 0x000055d52eb3c3b7 in io_wait_loop_epoll (h=0x55d52ec5da60 <_worker_io>, t=2, repeat=0) at net/../io_wait_loop.h:280
#25 0x000055d52eb3e5e1 in tcp_worker_proc_loop () at net/net_tcp_proc.c:411
#26 0x000055d52eb4eb50 in tcp_start_processes (chd_rank=0x55d52ec26f5c <chd_rank>, startup_done=0x0) at net/net_tcp.c:2076
#27 0x000055d52ea79b68 in main_loop () at main.c:804
#28 0x000055d52ea7cee4 in main (argc=15, argv=0x7ffed61463e8) at main.c:1483
bogdan-iancu commented 5 years ago

@danpascu , to be sure we test the crash and not the deadlock (from #1767), could you share the change you did there ?

danpascu commented 5 years ago

I could, but this is the gist of the problem. That code was never executed so it was never part of the problem. The crash happens with or without that code. I tried to test if the deadlock from #1767 happens with the change, but I was unable because the thing crashes before I get any deadlock, which means I cannot confirm that that code works and fixes the deadlock.

If we include that code it will just be another extra variable to keep track of and another layer of uncertainty. Thus I'm not sure how adding some untested code which can have unexpected side effects improves the chances of fixing this crash. Unless you consistently get the deadlock but not the crash.

clifjones commented 5 years ago

Continuing my investigation results originally from: #1771

I'm still seeing tons of TLS crashes on the latest OpenSIPS 2.4.6. I am running on Amazon Linux 2 and since Amazon's OpenSSL 1.0.2k+ exhibits the double-free, I have tried other combinations and even disabled the OpenSIPS shared memory hooks for OpenSSL without clean results.

Using generic OpenSSL 1.0.2s, there were no start-up errors with the double-free that I saw before, but I saw crashes in processing traffic.

[New LWP 7560]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/local/sbin/opensips -P /var/run/inin/opensips-forward.pid -f /home/pcv-sip'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00007eff6a00dff7 in SSL_set_bio () from /lib64/libssl.so.10

Thread 1 (Thread 0x7effaf881740 (LWP 7560)):
#0  0x00007eff6a00dff7 in SSL_set_bio () from /lib64/libssl.so.10
No symbol table info available.
#1  0x00007eff6a00e1af in SSL_set_fd () from /lib64/libssl.so.10
No symbol table info available.
#2  0x00007eff613fbe6f in tls_update_fd (c=<optimized out>, fd=6) at ../tls_mgm/tls_conn.h:73
        ssl = <optimized out>
#3  0x00007eff6140bf87 in tls_read (r=0x7eff61613660 <tls_current_req>, c=0x7eff6b1a9f00) at ../tls_mgm/tls_conn_ops.h:236
        bytes_free = 65535
        fd = <optimized out>
#4  tls_read_req (con=0x7eff6b1a9f00, bytes_read=0x7ffc4a86f320) at proto_tls.c:561
        bytes = <optimized out>
        total_bytes = 0
        req = <optimized out>
        data = <optimized out>
        __FUNCTION__ = "tls_read_req"
#5  0x00000000005f5137 in handle_io (event_type=1, idx=0, fm=<optimized out>) at net/net_tcp_proc.c:241
        con = <optimized out>
        ret = 0
        n = <optimized out>
        rw = <optimized out>
        response = {9584996, 138540262299616}
        s = 0
        resp = <optimized out>
#6  io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:280
        ret = <optimized out>
        i = <optimized out>
        e = <optimized out>
        ep_event = {events = 0, data = {ptr = 0x0, fd = 0, u32 = 0, u64 = 0}}
        fd = <optimized out>
        n = 1
        r = 0
#7  tcp_worker_proc_loop () at net/net_tcp_proc.c:386
        __FUNCTION__ = "tcp_worker_proc_loop"
#8  0x0000000000603808 in tcp_start_processes (chd_rank=chd_rank@entry=0x924164 <chd_rank>, startup_done=startup_done@entry=0x7eff6b1f17e0) at net/net_tcp.c:1903
        r = 6
        reader_fd = {111, 113}
        pid = <optimized out>
        __FUNCTION__ = "tcp_start_processes"
#9  0x000000000041c1d1 in main_loop () at main.c:788
        startup_done = 0x7eff6b1f17e0
        rc = <optimized out>
        chd_rank = 23
#10 main (argc=<optimized out>, argv=<optimized out>) at main.c:1439
        cfg_stream = <optimized out>
        c = <optimized out>
        r = 0
        tmp = 0x7ffc4a870ecf ""
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x653928 "f:cCm:M:b:l:n:N:rRvdDFEVhw:t:u:g:P:G:W:o:"
        ret = -1
        seed = 3004798768
        rfd = <optimized out>
        __FUNCTION__ = "main"

[New LWP 10580]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/local/sbin/opensips -P /var/run/inin/opensips-forward.pid -f /home/pcv-sip'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007f7d69e7f760 in raise () from /lib64/libc.so.6

Thread 1 (Thread 0x7f7d6a833740 (LWP 10580)):
#0  0x00007f7d69e7f760 in raise () from /lib64/libc.so.6
No symbol table info available.
#1  0x00007f7d69e80d41 in abort () from /lib64/libc.so.6
No symbol table info available.
#2  0x00007f7d69ec2007 in __libc_message () from /lib64/libc.so.6
No symbol table info available.
#3  0x00007f7d69ec830a in malloc_printerr () from /lib64/libc.so.6
No symbol table info available.
#4  0x00007f7d69ec9e4c in _int_free () from /lib64/libc.so.6
No symbol table info available.
#5  0x00007f7d24b8e6bd in CRYPTO_free () from /lib64/libcrypto.so.10
No symbol table info available.
#6  0x00007f7d1c3af8d9 in tls_conn_clean (c=0x7f7d262760c0) at ../tls_mgm/tls_conn_ops.h:150
No locals.
#7  proto_tls_conn_clean (c=c@entry=0x7f7d262760c0) at proto_tls.c:353
        data = <optimized out>
#8  0x00000000005f8f25 in _tcpconn_rm (c=0x7f7d262760c0) at net/net_tcp.c:724
        r = <optimized out>
#9  0x00000000005f9183 in tcpconn_destroy (tcpconn=0x7f7d262760c0) at net/net_tcp.c:988
        fd = 139
        id = <optimized out>
#10 0x000000000041760c in handle_tcp_worker (fd_i=16, tcp_c=0x7f7d65ed7ee0) at net/net_tcp.c:1316
        tcpconn = 0x7f7d262760c0
        bytes = 16
        response = {140175487754432, -3}
        cmd = -3
#11 handle_io (fm=<optimized out>, idx=idx@entry=41, event_type=event_type@entry=1) at net/net_tcp.c:1506
        ret = 0
        __FUNCTION__ = "handle_io"
#12 0x00000000006000b3 in io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:280
        ret = <optimized out>
        i = <optimized out>
        e = <optimized out>
        ep_event = {events = 0, data = {ptr = 0x0, fd = 0, u32 = 0, u64 = 0}}
        fd = <optimized out>
        n = 1
        r = 41
#13 tcp_main_server () at net/net_tcp.c:1672
        last_sec = 12
        flags = <optimized out>
        si = <optimized out>
        n = <optimized out>
        __FUNCTION__ = "tcp_main_server"
#14 0x0000000000603d47 in tcp_start_listener () at net/net_tcp.c:1941
        pid = <optimized out>
        __FUNCTION__ = "tcp_start_listener"
#15 0x000000000041c2ea in main_loop () at main.c:800
        startup_done = 0x7f7d2619e020
        rc = <optimized out>
        chd_rank = 25
#16 main (argc=<optimized out>, argv=<optimized out>) at main.c:1439
        cfg_stream = <optimized out>
        c = <optimized out>
        r = 0
        tmp = 0x7ffe5d627ecf ""
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x653928 "f:cCm:M:b:l:n:N:rRvdDFEVhw:t:u:g:P:G:W:o:"
        ret = -1
        seed = 1108817144
        rfd = <optimized out>
        __FUNCTION__ = "main"

[New LWP 324]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/local/sbin/opensips -P /var/run/genesys/opensips-forward.pid -f /opensips/'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x0000000000000001 in ?? ()

Thread 1 (Thread 0x7f7d4e79c740 (LWP 324)):
#0  0x0000000000000001 in ?? ()
No symbol table info available.
#1  0x00007f7d38315dc5 in tls_accept (c=c@entry=0x7f7d420f7cf0, poll_events=poll_events@entry=0x0) at ../tls_mgm/tls_conn_server.h:242
        ret = <optimized out>
        err = <optimized out>
        ssl = <optimized out>
        cert = <optimized out>
        tls_err_s = {s = 0x6 <error: Cannot access memory at address 0x6>, len = 31905392}
#2  0x00007f7d38324ff0 in tls_accept (poll_events=0x0, c=0x7f7d420f7cf0) at ../../net/proto_tcp/tcp_common.h:160
No locals.
#3  tls_fix_read_conn (t_dst=0x0, c=0x7f7d420f7cf0) at ../tls_mgm/tls_conn_server.h:501
        ret = 0
#4  tls_read_req (con=0x7f7d420f7cf0, bytes_read=0x7ffd1dbc5720) at proto_tls.c:525
        bytes = -1
        total_bytes = 0
        req = 0x7f7d3852b660 <tls_current_req>
        data = <optimized out>
        __FUNCTION__ = "tls_read_req"
#5  0x00000000005f5247 in handle_io (event_type=1, idx=0, fm=<optimized out>) at net/net_tcp_proc.c:241
        con = <optimized out>
        ret = 0
        n = <optimized out>
        rw = <optimized out>
        response = {9584964, 139639085023584}
        s = 0
        resp = <optimized out>
#6  io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:280
        ret = <optimized out>
        i = <optimized out>
        e = <optimized out>
        ep_event = {events = 0, data = {ptr = 0x0, fd = 0, u32 = 0, u64 = 0}}
        fd = <optimized out>
        n = 1
        r = 0
#7  tcp_worker_proc_loop () at net/net_tcp_proc.c:386
        __FUNCTION__ = "tcp_worker_proc_loop"
#8  0x0000000000603918 in tcp_start_processes (chd_rank=chd_rank@entry=0x924144 <chd_rank>, startup_done=startup_done@entry=0x7f7d420f4160) at net/net_tcp.c:1903
        r = 0
        reader_fd = {100, 101}
        pid = <optimized out>
        __FUNCTION__ = "tcp_start_processes"
#9  0x000000000041c1d1 in main_loop () at main.c:788
        startup_done = 0x7f7d420f4160
        rc = <optimized out>
        chd_rank = 17
#10 main (argc=<optimized out>, argv=<optimized out>) at main.c:1439
        cfg_stream = <optimized out>
        c = <optimized out>
        r = 0
        tmp = 0x7ffd1dbc5e3c ""
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x6536b8 "f:cCm:M:b:l:n:N:rRvdDFEVhw:t:u:g:P:G:W:o:"
        ret = -1
        seed = 2740982126
        rfd = <optimized out>
        __FUNCTION__ = "main"

I ran again with TCP async disabled, with no better results.

[New LWP 323]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/local/sbin/opensips -P /var/run/genesys/opensips-forward.pid -f /opensips/'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x0000000000000001 in ?? ()

Thread 1 (Thread 0x7f4a9332a740 (LWP 323)):
#0  0x0000000000000001 in ?? ()
No symbol table info available.
#1  0x00007f4a7cea3dc5 in tls_accept (c=c@entry=0x7f4a86c85cf0, poll_events=poll_events@entry=0x0) at ../tls_mgm/tls_conn_server.h:242
        ret = <optimized out>
        err = <optimized out>
        ssl = <optimized out>
        cert = <optimized out>
        tls_err_s = {s = 0x6 <error: Cannot access memory at address 0x6>, len = 41150064}
#2  0x00007f4a7ceb2ff0 in tls_accept (poll_events=0x0, c=0x7f4a86c85cf0) at ../../net/proto_tcp/tcp_common.h:160
No locals.
#3  tls_fix_read_conn (t_dst=0x0, c=0x7f4a86c85cf0) at ../tls_mgm/tls_conn_server.h:501
        ret = 0
#4  tls_read_req (con=0x7f4a86c85cf0, bytes_read=0x7fff6e430070) at proto_tls.c:525
        bytes = -1
        total_bytes = 0
        req = 0x7f4a7d0b9660 <tls_current_req>
        data = <optimized out>
        __FUNCTION__ = "tls_read_req"
#5  0x00000000005f5247 in handle_io (event_type=1, idx=0, fm=<optimized out>) at net/net_tcp_proc.c:241
        con = <optimized out>
        ret = 0
        n = <optimized out>
        rw = <optimized out>
        response = {9584964, 139640237990240}
        s = 0
        resp = <optimized out>
#6  io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:280
        ret = <optimized out>
        i = <optimized out>
        e = <optimized out>
        ep_event = {events = 0, data = {ptr = 0x0, fd = 0, u32 = 0, u64 = 0}}
        fd = <optimized out>
        n = 1
        r = 0
#7  tcp_worker_proc_loop () at net/net_tcp_proc.c:386
        __FUNCTION__ = "tcp_worker_proc_loop"
#8  0x0000000000603918 in tcp_start_processes (chd_rank=chd_rank@entry=0x924144 <chd_rank>, startup_done=startup_done@entry=0x7f4a86c82160) at net/net_tcp.c:1903
        r = 0
        reader_fd = {100, 101}
        pid = <optimized out>
        __FUNCTION__ = "tcp_start_processes"
#9  0x000000000041c1d1 in main_loop () at main.c:788
        startup_done = 0x7f4a86c82160
        rc = <optimized out>
        chd_rank = 17
#10 main (argc=<optimized out>, argv=<optimized out>) at main.c:1439
        cfg_stream = <optimized out>
        c = <optimized out>
        r = 0
        tmp = 0x7fff6e430e3c ""
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x6536b8 "f:cCm:M:b:l:n:N:rRvdDFEVhw:t:u:g:P:G:W:o:"
        ret = -1
        seed = 3335358000
        rfd = <optimized out>
        __FUNCTION__ = "main"

Finally, I advanced OpenSSL to 1.1.1c and left TCP async disabled.

[New LWP 12344]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/local/sbin/opensips -P /var/run/genesys/opensips-forward.pid -f /home/pcv-'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  fm_remove_free (n=0x7f8ec44faa38, qm=0x7f8ec3c39000) at mem/f_malloc.c:209
209     *pf=n->u.nxt_free;

Thread 1 (Thread 0x7f8f08622740 (LWP 12344)):
#0  fm_remove_free (n=0x7f8ec44faa38, qm=0x7f8ec3c39000) at mem/f_malloc.c:209
        pf = 0x0
        hash = 33
#1  fm_malloc (qm=0x7f8ec3c39000, size=size@entry=264) at mem/f_malloc.c:438
        frag = 0x7f8ec44faa38
        n = <optimized out>
        hash = <optimized out>
        __FUNCTION__ = "fm_malloc"
#2  0x00007f8eb980983f in shm_malloc (size=264) at ../../mem/shm_mem.h:437
        p = <optimized out>
#3  os_malloc (size=264, file=<optimized out>, line=<optimized out>) at tls.h:89
No locals.
#4  0x00007f8eb9ba8ae9 in CRYPTO_zalloc () from /lib64/libcrypto.so.1.1
No symbol table info available.
#5  0x00007f8eb9b96fc9 in EVP_CipherInit_ex () from /lib64/libcrypto.so.1.1
No symbol table info available.
#6  0x00007f8eb9bd2c11 in ctr_update () from /lib64/libcrypto.so.1.1
No symbol table info available.
#7  0x00007f8eb9bd3b68 in drbg_ctr_generate () from /lib64/libcrypto.so.1.1
No symbol table info available.
#8  0x00007f8eb9bd5b69 in RAND_DRBG_generate () from /lib64/libcrypto.so.1.1
No symbol table info available.
#9  0x00007f8eb9bd5e02 in RAND_DRBG_bytes () from /lib64/libcrypto.so.1.1
No symbol table info available.
#10 0x00007f8eb9f2d71e in tls1_enc () from /lib64/libssl.so.1.1
No symbol table info available.
#11 0x00007f8eb9f2a9c0 in do_ssl3_write () from /lib64/libssl.so.1.1
No symbol table info available.
#12 0x00007f8eb9f2b0c1 in ssl3_write_bytes () from /lib64/libssl.so.1.1
No symbol table info available.
#13 0x00007f8eb9f3fccc in ssl_write_internal () from /lib64/libssl.so.1.1
No symbol table info available.
#14 0x00007f8eb9f3fee5 in SSL_write () from /lib64/libssl.so.1.1
No symbol table info available.
#15 0x00007f8eba19eb86 in tls_write (c=c@entry=0x7f8ec40fc510, buf=buf@entry=0x7f8f03cf1198, len=len@entry=375, poll_events=poll_events@entry=0x7ffeca1db464, fd=<optimized out>) at ../tls_mgm/tls_conn_server.h:529
        ret = <optimized out>
        err = <optimized out>
        ssl = 0x7f8ec40fc6a0
#16 0x00007f8eba1afc6d in tls_blocking_write (api=0x7f8eba3c47a0 <tls_mgm_api>, api=0x7f8eba3c47a0 <tls_mgm_api>, t_dst=0x0, len=375, buf=0x7f8f03cf1198 "SIP/2.0 100 Trying\r\nTo:  <sip:12287281027@testacdload27.byoc.inintca.com:5061>\r\nFrom:  <sip:+99529887555450@testacdload27.byoc.inintca.com:5061>;tag=759103\r\ncall-id: 57cbf66b-9b07-4cd8-a46f-e420743135"..., fd=<optimized out>, c=0x7f8ec40fc510) at ../tls_mgm/tls_conn_server.h:603
        written = 0
        timeout = <optimized out>
        pf = {fd = 120, events = 0, revents = 0}
        n = 0
        retries = 0
#17 proto_tls_send (send_sock=0x7f8f03c97c10, buf=<optimized out>, len=<optimized out>, to=<optimized out>, id=<optimized out>) at proto_tls.c:475
        c = 0x7f8ec40fc510
        ip = {af = 2, len = 4, u = {addrl = {2048780306, 0}, addr32 = {2048780306, 0, 0, 0}, addr16 = {59410, 31261, 0, 0, 0, 0, 0, 0}, addr = "\022\350\035z", '\000' <repeats 11 times>}}
        fd = 120
        n = <optimized out>
        __FUNCTION__ = "proto_tls_send"
#18 0x00007f8ec3a34a73 in msg_send (msg=0x0, len=<optimized out>, buf=0x7f8f03cf1198 "SIP/2.0 100 Trying\r\nTo:  <sip:12287281027@testacdload27.byoc.inintca.com:5061>\r\nFrom:  <sip:+99529887555450@testacdload27.byoc.inintca.com:5061>;tag=759103\r\ncall-id: 57cbf66b-9b07-4cd8-a46f-e420743135"..., id=<optimized out>, to=0x7ffeca1db520, proto=<optimized out>, send_sock=0x7f8f03c97c10) at ../../forward.h:123
        out_buff = {s = 0x7f8f03cf1198 "SIP/2.0 100 Trying\r\nTo:  <sip:12287281027@testacdload27.byoc.inintca.com:5061>\r\nFrom:  <sip:+99529887555450@testacdload27.byoc.inintca.com:5061>;tag=759103\r\ncall-id: 57cbf66b-9b07-4cd8-a46f-e420743135"..., len = 375}
#19 sl_send_reply_helper (msg=<optimized out>, code=100, text=<optimized out>) at sl_funcs.c:192
        buf = {s = 0x7f8f03cf1198 "SIP/2.0 100 Trying\r\nTo:  <sip:12287281027@testacdload27.byoc.inintca.com:5061>\r\nFrom:  <sip:+99529887555450@testacdload27.byoc.inintca.com:5061>;tag=759103\r\ncall-id: 57cbf66b-9b07-4cd8-a46f-e420743135"..., len = 375}
        dset = <optimized out>
        dset_len = 32766
        dummy_bm = {to_tag_val = {s = 0x0, len = 0}}
        backup_mhomed = 0
        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}}
        text = <optimized out>
        msg = <optimized out>
        code = 100
#20 0x00007f8ec3a36fcb in w_sl_send_reply (msg=0x7f8f03cee0a0, str1=<optimized out>, str2=<optimized out>) at sl.c:242
        code_s = {s = 0x7f8f03c8f2b0 "Trying", len = 6}
        code_i = <optimized out>
#21 0x0000000000430427 in do_action (a=a@entry=0x7f8f03c8f348, msg=msg@entry=0x7f8f03cee0a0) at action.c:1866
        increment = <optimized out>
        decrement = <optimized out>
        j = <optimized out>
        num_rows = 134149632
        val_s = {s = 0x7f8f03c73a10 "\002", len = 2}
        cdb_reply = 0x1dd8780
        num_cols = <optimized out>
        aux = {s = 0x7f8f03c73a10 "\002", len = 2}
        i = <optimized out>
        it = <optimized out>
        avp_val = <optimized out>
        avp_name = {n = 63388176, s = {s = 0x7f8f03c73a10 "\002", len = 2}}
        avp_type = 0
        ret = -5
        v = <optimized out>
        sec = <optimized out>
        usec = <optimized out>
        to = <optimized out>
        p = <optimized out>
        tmp = <optimized out>
        new_uri = <optimized out>
        end = <optimized out>
        crt = <optimized out>
        len = <optimized out>
        i = <optimized out>
        user = 0
        expires = 0
        vals = {{s = 0x1dd8780 "/etc/localtime", len = 1567789186}, {s = 0x1 <error: Cannot access memory at address 0x1>, len = 134149632}, {s = 0x7ffeca1db758 "\341\003R", len = 134149632}, {s = 0x7f8f03c50b1a "0,6})", len = 1}, {s = 0x7ffeca1db730 "\330\f\305\003\217\177", len = -904021968}}
        result = {s = 0x100006d6f6303 <error: Cannot access memory at address 0x100006d6f6303>, len = 835585}
        uri = {user = {s = 0x7f8f03c50cd8 "\002", len = 63889568}, passwd = {s = 0x7ffeca1db830 "`\273\220", len = 63245344}, host = {s = 0x7ffeca1db830 "`\273\220", len = 63889568}, port = {s = 0x7f8f03c50cd8 "\002", len = 63889568}, params = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 5012828}, headers = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 5374945}, port_no = 2976, proto = 965, type = 32655, transport = {s = 0x7f8f03cee0a0 "A\004", len = -904021968}, ttl = {s = 0x4fb78c <pv_get_spec_value+285> "\351K\377\377\377L\213h\020M\205\355t\305H\213\025\347\251@", len = -904021856}, user_param = {s = 0x7ffeca1db980 "\003", len = 30}, maddr = {s = 0x0, len = 7}, method = {s = 0x7f8f03cee0a0 "A\004", len = 3}, lr = {s = 0x47fce2 <eval_elem+1536> "H\205\300\017\204W\f", len = -904021912}, r2 = {s = 0xd3736f36f5f44700 <error: Cannot access memory at address 0xd3736f36f5f44700>, len = 31857360}, gr = {s = 0x1e38240 "", len = -904021552}, transport_val = {s = 0x1e38238 <incomplete sequence \361>, len = 2}, ttl_val = {s = 0x7f8ebdb22909 <pv_get_stat+515> "\211C\020Lc\330M\205\333\017\210\177\004", len = -904021552}, user_param_val = {s = 0x7f8f07c66a0c <newlocale+1964> "\351N\372\377\377L\213\265X\376\377\377H\211\307\017\037D", len = 1}, maddr_val = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 31687232}, method_val = {s = 0x7ffeca1db840 "2\206\n", len = 9485152}, lr_val = {s = 0x6 <error: Cannot access memory at address 0x6>, len = 689714}, r2_val = {s = 0x7f8f07db55d3 <_nl_C_name> "C", len = -1110235988}, gr_val = {s = 0x7f8ebdd324ac "C", len = -1110235988}, u_name = {{s = 0x7f8ebdd324ac "C", len = 0}, {s = 0x7f8f03c738a8 "\266\004", len = 63889568}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 63388096}, {s = 0x7f8f03cee0a0 "A\004", len = 3}, {s = 0x4fb76c <pv_get_spec_value+253> "\205\300\017\205h\377\377\377H\213s`H\205\366\017\204[\377\377\377L\211\342H\211\357\350\245\305\374\377\351K\377\377\377L\213h\020M\205\355t\305H\213\025\347\251@", len = 5}, {s = 0x7ffeca1dba90 "", len = 30}, {s = 0x0, len = 11}, {s = 0x7f8f03cee0a0 "A\004", len = 3}, {s = 0x47fce2 <eval_elem+1536> "H\205\300\017\204W\f", len = -80}, {s = 0xa <error: Cannot access memory at address 0xa>, len = -904021440}}, u_val = {{s = 0x7f8f03cee0a0 "A\004", len = 63247120}, {s = 0x7ffeca1dba60 "", len = -904021408}, {s = 0x7f8ebdb22909 <pv_get_stat+515> "\211C\020Lc\330M\205\333\017\210\177\004", len = 131814867}, {s = 0x3e20 <error: Cannot access memory at address 0x3e20>, len = 640}, {s = 0x7f8f07feac40 <main_arena> "", len = 31973856}, {s = 0x7f8f03c512f8 "S\004", len = 9816461}, {s = 0xa <error: Cannot access memory at address 0xa>, len = 1073741824}, {s = 0x7f8f03cee0a0 "A\004", len = 3}, {s = 0x4fb76c <pv_get_spec_value+253> "\205\300\017\205h\377\377\377H\213s`H\205\366\017\204[\377\377\377L\211\342H\211\357\350\245\305\374\377\351K\377\377\377L\213h\020M\205\355t\305H\213\025\347\251@", len = 0}, {s = 0xd3736f36f5f44700 <error: Cannot access memory at address 0xd3736f36f5f44700>, len = 0}}, u_params_no = 3}
        next_hop = {user = {s = 0x7f8f03c73a10 "\002", len = 2}, passwd = {s = 0x7f8f03cee0a0 "A\004", len = -904021328}, host = {s = 0x3 <error: Cannot access memory at address 0x3>, len = -904021360}, port = {s = 0x7 <error: Cannot access memory at address 0x7>, len = 5246387}, params = {s = 0x7ffeca1dbbe0 "\240\274\035\312\376\177", len = 7}, headers = {s = 0x2 <error: Cannot access memory at address 0x2>, len = 10737418}, port_no = 57504, proto = 974, type = 32655, transport = {s = 0x47faf9 <eval_elem+1047> "H\205\333t\004D\211k\020E1\344E\205\355A\017\225\304\351j\374\377\377D\213\254$\200", len = 0}, ttl = {s = 0x7f8eb91c5f0e <gethostbyname3_context+174> "H\205\300\017\204\241\002", len = -904021384}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x400 <error: Cannot access memory at address 0x400>, len = 31724848}, method = {s = 0x7f8f086226c0 "", len = 0}, lr = {s = 0x1e52c50 "\260\f\347\001", len = 3}, r2 = {s = 0x7ffeca1db620 "\177ځ\200", len = 63898080}, gr = {s = 0x4 <error: Cannot access memory at address 0x4>, len = 0}, transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x7f8f03c70390 "\002", len = 0}, user_param_val = {s = 0x7f8f03c8e3e8 "\020", len = 2}, maddr_val = {s = 0x7f8f03cee0a0 "A\004", len = 63497416}, method_val = {s = 0x7f8f03cee0a0 "A\004", len = 0}, lr_val = {s = 0x437b76 <run_action_list+71> "\211Ņ\300u\a\203\r\225.M", len = 63889568}, r2_val = {s = 0x7f8f03c8f000 "\020", len = 2}, gr_val = {s = 0x7f8f03cee0a0 "A\004", len = 63500512}, u_name = {{s = 0x7f8f03cee0a0 "A\004", len = 0}, {s = 0x437b76 <run_action_list+71> "\211Ņ\300u\a\203\r\225.M", len = 0}, {s = 0x47fa56 <eval_elem+884> "\351\301\375\377\377A\274\373\377\377\377L\213- gH", len = 63592880}, {s = 0x0, len = 2}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 63500512}, {s = 0x7f8f03cee0a0 "A\004", len = 0}, {s = 0x47fa56 <eval_elem+884> "\351\301\375\377\377A\274\373\377\377\377L\213- gH", len = 2}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 63592880}, {s = 0x7f8f03cee0a0 "A\004", len = 0}, {s = 0x47fa56 <eval_elem+884> "\351\301\375\377\377A\274\373\377\377\377L\213- gH", len = 257}}, u_val = {{s = 0x4 <error: Cannot access memory at address 0x4>, len = 0}, {s = 0x0, len = 0}, {s = 0x7f8f00000000 "", len = -904020832}, {s = 0x4ec2e9 <pv_set_scriptvar+67> "H\205\300\017\204\016\001", len = -1172634411}, {s = 0x3 <error: Cannot access memory at address 0x3>, len = 63497416}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 63889568}, {s = 0x0, len = 0}, {s = 0x47f5af <eval_expr+404> "\213\035\033\271H", len = 63591472}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 63500512}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 63889568}}, u_params_no = 0}
        u = <optimized out>
        port = 26990
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        model = <optimized out>
        val = {rs = {s = 0x7f8f07fef600 <_tmbuf> ".", len = 131005146}, ri = -904020535, flags = 32766}
        pve = <optimized out>
        name_s = {s = 0xa3200a04003a0000 <error: Cannot access memory at address 0xa3200a04003a0000>, len = 835795}
        start = {tv_sec = -4170322242645131264, tv_usec = 281479272513676}
        aux_counter = 1633907822
        __FUNCTION__ = "do_action"
#22 0x0000000000437b76 in run_action_list (a=<optimized out>, msg=msg@entry=0x7f8f03cee0a0) at action.c:172
        ret = -1
        t = 0x7f8f03c8f348
#23 0x0000000000434f89 in do_action (a=a@entry=0x7f8f03c8f428, msg=msg@entry=0x7f8f03cee0a0) at action.c:1124
        increment = <optimized out>
        decrement = <optimized out>
        j = <optimized out>
        num_rows = -904016456
        val_s = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 1263}
        cdb_reply = 0x0
        num_cols = <optimized out>
        aux = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 1263}
        i = <optimized out>
        it = <optimized out>
        avp_val = <optimized out>
        avp_name = {n = 1, s = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 1263}}
        avp_type = 51552
        ret = 1
        v = 1
        sec = <optimized out>
        usec = <optimized out>
        to = <optimized out>
        p = <optimized out>
        tmp = <optimized out>
        new_uri = <optimized out>
        end = <optimized out>
        crt = <optimized out>
        len = <optimized out>
        i = <optimized out>
        user = 0
        expires = 0
        vals = {{s = 0x0, len = 31724880}, {s = 0x7fffffff <error: Cannot access memory at address 0x7fffffff>, len = 992}, {s = 0x1e4192f "\377&", len = -168540416}, {s = 0x3e0 <error: Cannot access memory at address 0x3e0>, len = 31677792}, {s = 0x0, len = 0}}
        result = {s = 0x1e7de89 "-0cd5-402d-b894-fe97f1e770e0\", \"sipStatus\": 100, \"sipReason\": \"Trying\", \"mflags\": \"PRIVATE_DEST PROV_RESP_RCVD SIP_MESSAGE\", \"conversation\": \"9395234c-6823-4a91-81d7-5e37ce672938\" }", len = 130765282}
        uri = {user = {s = 0x2 <error: Cannot access memory at address 0x2>, len = 31724936}, passwd = {s = 0x0, len = 130765019}, host = {s = 0x7f8f07cb4470 <flush_cleanup> "H\213\005\031\204\063", len = -168540416}, port = {s = 0x0, len = 31677792}, params = {s = 0x0, len = 131249172}, headers = {s = 0x0, len = 31531296}, port_no = 48824, proto = 51741, type = 32766, transport = {s = 0x7f8f07d51540 <known_compare> "H9\367t\vH\213\066H\213?\351\360\221\360\377\061\300\303\017\037", len = 9550720}, ttl = {s = 0x7ffeca1dbf90 "\200\377\377\377\377\377\377\377", len = -904020224}, user_param = {s = 0xd3736f36f5f44700 <error: Cannot access memory at address 0xd3736f36f5f44700>, len = -904020296}, maddr = {s = 0x7f8f086226c0 "", len = 31796304}, method = {s = 0x7f8f07fee320 <resbuf> "\b\027\344\001", len = 31724848}, lr = {s = 0x400 <error: Cannot access memory at address 0x400>, len = -904019988}, r2 = {s = 0x7f8eb91c6a55 <_nss_dns_gethostbyname_r+101> "H\203\304 L\211\347\211D$\b\350\353\344\377\377\213D$\bH\203\304\030[]A\\A]A^A_\303\017\037\204", len = 140650176}, gr = {s = 0x7ffeca1dbfec "", len = 0}, transport_val = {s = 0x7f8eb91c6a65 <_nss_dns_gethostbyname_r+117> "\213D$\bH\203\304\030[]A\\A]A^A_\303\017\037\204", len = -904020088}, ttl_val = {s = 0xd3736f36f5f44700 <error: Cannot access memory at address 0xd3736f36f5f44700>, len = 131819100}, user_param_val = {s = 0x7ffeca1dbfec "", len = 1}, maddr_val = {s = 0x7f8f07fee320 <resbuf> "\b\027\344\001", len = 1}, method_val = {s = 0x91bb80 <tmp> "pcv-homer-hep-nlb.us-east-1.inintca.com", len = -128}, lr_val = {s = 0x7f8f07d42020 <gethostbyname_r@@GLIBC_2.2.5+608> "\213T$D\203\372\001\017\206\033\001", len = 31291984}, r2_val = {s = 0x7f8f086226c0 "", len = -904020080}, gr_val = {s = 0x7ffeca1dbf88 "P,\345\001", len = -904019984}, u_name = {{s = 0x1e52c50 "\260\f\347\001", len = 0}, {s = 0xd3736f36f5f44700 <error: Cannot access memory at address 0xd3736f36f5f44700>, len = 134147040}, {s = 0x1e52c50 "\260\f\347\001", len = -128}, {s = 0x0, len = 134144800}, {s = 0x1e52c50 "\260\f\347\001", len = 0}, {s = 0x7f8f07d50113 <context_free+51> "dD\211e", len = 9550720}, {s = 0x7ffeca1dbff0 " \343\376\a\217\177", len = -904019988}, {s = 0x7f8f07d41565 <gethostbyname+421> "\213D$\f\205\300u#H\213D$\020H\213L$\030dH3\f%(", len = 3}, {s = 0x3 <error: Cannot access memory at address 0x3>, len = 134144800}, {s = 0xd3736f36f5f44700 <error: Cannot access memory at address 0xd3736f36f5f44700>, len = -1010549792}}, u_val = {{s = 0x7f8f03cefc3c "\b", len = 0}, {s = 0x7f8f03c99489 ":9060; transport=udp; version=3", len = 1}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x7f8f03cefc40 "p\367\316\003\217\177", len = 63898096}, {s = 0x10 <error: Cannot access memory at address 0x10>, len = 2}, {s = 0x7f8f07fee320 <resbuf> "\b\027\344\001", len = 2}, {s = 0x7f8eba5e75f8 <hep_udp_send+99> "A\211ƃ\370\377\017\205@\001", len = 3}, {s = 0x4fedd7 <pv_get_avp+530> "I\211\305H\205\300\017\205\375\002", len = 0}}, u_params_no = 0}
        next_hop = {user = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 1263}, passwd = {s = 0x1000000010 <error: Cannot access memory at address 0x1000000010>, len = -904019736}, host = {s = 0x4ef <error: Cannot access memory at address 0x4ef>, len = 63896616}, port = {s = 0x4ef <error: Cannot access memory at address 0x4ef>, len = 4458897}, params = {s = 0x7f8f03cdb9e0 "\"", len = 63814264}, headers = {s = 0x7f8f03cee0a0 "A\004", len = -904019600}, port_no = 47888, proto = 973, type = 32655, transport = {s = 0x7f8f03d27c18 "\370\272\315\003\217\177", len = 5}, ttl = {s = 0x4ec2e9 <pv_set_scriptvar+67> "H\205\300\017\204\016\001", len = -904019392}, user_param = {s = 0x7a <error: Cannot access memory at address 0x7a>, len = 5}, maddr = {s = 0x7f8f03d22d08 "\002", len = 63889568}, method = {s = 0x7f8f03d27c18 "\370\272\315\003\217\177", len = 5}, lr = {s = 0x4fb5a2 <pv_set_value+199> "H\203\304\070[]\303H\213o\020H\205\355t\347H\211L$\030\211T$\024H\211t$\bH\211\337\377\325H\211\303H\215@\377H\203\370\375w\024H\213t$\bH\213F\020\213T$\024H\213L$\030\353\263H\213\025\233\253@", len = 9816444}, r2 = {s = 0x5 <error: Cannot access memory at address 0x5>, len = 60014}, gr = {s = 0x7f8ec3f9c608 "ԒK\276\216\177", len = 63889568}, transport_val = {s = 0x7f8f03d27c18 "\370\272\315\003\217\177", len = -1161426912}, ttl_val = {s = 0x7f8f03cee0a0 "A\004", len = 64125976}, user_param_val = {s = 0x7f8ebaa4d3ec <get_source_group+1253> "\205\300\017\210", <incomplete sequence \326>, len = 63889568}, maddr_val = {s = 0x7f8f03cee270 "\002", len = -1100214088}, method_val = {s = 0x7f8ec3f9e458 "\250\307\371Î\177", len = -1100214096}, lr_val = {s = 0x7f8f03ca3470 "\020", len = 2}, r2_val = {s = 0x7f8f03cee0a0 "A\004", len = 63583568}, gr_val = {s = 0x7f8f03cee0a0 "A\004", len = 0}, u_name = {{s = 0x437b76 <run_action_list+71> "\211Ņ\300u\a\203\r\225.M", len = 63889696}, {s = 0x7f8f03ca26c8 "\a", len = 2}, {s = 0x0, len = 2}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 63583568}, {s = 0x7f8f03cee0a0 "A\004", len = 0}, {s = 0x47fa56 <eval_elem+884> "\351\301\375\377\377A\274\373\377\377\377L\213- gH", len = 7}, {s = 0x0, len = 2}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 63580072}, {s = 0x7f8f03cee0a0 "A\004", len = 0}, {s = 0x47fa56 <eval_elem+884> "\351\301\375\377\377A\274\373\377\377\377L\213- gH", len = 63567192}}, u_val = {{s = 0x10 <error: Cannot access memory at address 0x10>, len = -1100215712}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 0}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 53}, {s = 0x7 <error: Cannot access memory at address 0x7>, len = 0}, {s = 0x4fda70 <pv_set_avp+659> "\205\300xF1\300\351\300\376\377\377H\205\311f\220\017\204\270\001", len = -1168234461}, {s = 0x7ffeca1dc3d0 "\a", len = 7}, {s = 0x7f8ec4a51000 "", len = -1168233056}, {s = 0x3 <error: Cannot access memory at address 0x3>, len = 63583568}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 63889568}, {s = 0x0, len = 0}}, u_params_no = 62895}
        u = <optimized out>
        port = 0
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        model = <optimized out>
        val = {rs = {s = 0x1ca1dcdb8 <error: Cannot access memory at address 0x1ca1dcdb8>, len = 0}, ri = 1024, flags = 0}
        pve = <optimized out>
        name_s = {s = 0x400 <error: Cannot access memory at address 0x400>, len = 0}
        start = {tv_sec = 31724880, tv_usec = 140252287763202}
        aux_counter = 0
        __FUNCTION__ = "do_action"
#24 0x0000000000437b76 in run_action_list (a=<optimized out>, msg=0x7f8f03cee0a0) at action.c:172
        ret = -1
        t = 0x7f8f03c8f428
#25 0x0000000000437eb7 in run_actions (a=<optimized out>, msg=<optimized out>) at action.c:137
        ret = <optimized out>
        msg = <optimized out>
        a = <optimized out>
        ret = <optimized out>
#26 0x0000000000433c21 in do_action (a=a@entry=0x7f8f03ca79e0, msg=msg@entry=0x7f8f03cee0a0) at action.c:761
        increment = <optimized out>
        decrement = <optimized out>
        j = <optimized out>
        num_rows = 9816536
        val_s = {s = 0x1 <error: Cannot access memory at address 0x1>, len = -904017816}
        cdb_reply = 0x40
        num_cols = <optimized out>
        aux = {s = 0x1 <error: Cannot access memory at address 0x1>, len = -904017816}
        i = <optimized out>
        it = <optimized out>
        avp_val = <optimized out>
        avp_name = {n = 1, s = {s = 0x1 <error: Cannot access memory at address 0x1>, len = -904017816}}
        avp_type = 1024
        ret = -5
        v = <optimized out>
        sec = <optimized out>
        usec = <optimized out>
        to = <optimized out>
        p = <optimized out>
        tmp = <optimized out>
        new_uri = <optimized out>
        end = <optimized out>
        crt = <optimized out>
        len = <optimized out>
        i = <optimized out>
        user = 0
        expires = 0
        vals = {{s = 0x40 <error: Cannot access memory at address 0x40>, len = -904018448}, {s = 0xffffffffffffffb0 <error: Cannot access memory at address 0xffffffffffffffb0>, len = 0}, {s = 0x3000000002 <error: Cannot access memory at address 0x3000000002>, len = 0}, {s = 0x0, len = 91}, {s = 0x770000007c <error: Cannot access memory at address 0x770000007c>, len = 0}}
        result = {s = 0x0, len = 0}
        uri = {user = {s = 0x1e416d0 "D\027\344\001", len = 4}, passwd = {s = 0xffffffffffffffb0 <error: Cannot access memory at address 0xffffffffffffffb0>, len = 4}, host = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 0}, port = {s = 0x7ffeca1dc6d0 "(\177\224", len = 130793353}, params = {s = 0x0, len = -168540416}, headers = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 0}, port_no = 3, proto = 0, type = ERROR_URI_T, transport = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 0}, ttl = {s = 0x0, len = -904018224}, user_param = {s = 0x7f8f07d14638 <re_search_internal+4472> "\351\246\374\377\377\017\037", len = 9550720}, maddr = {s = 0x0, len = 4}, method = {s = 0x1000100000001e8 <error: Cannot access memory at address 0x1000100000001e8>, len = 31677296}, lr = {s = 0x3 <error: Cannot access memory at address 0x3>, len = -904018280}, r2 = {s = 0x100000001 <error: Cannot access memory at address 0x100000001>, len = 31697168}, gr = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 63647432}, transport_val = {s = 0x0, len = -904018272}, ttl_val = {s = 0x1e59cb0 "", len = -904018276}, user_param_val = {s = 0x947f28 <tcp_current_req+8> "100 Trying\r\nTo: <sip:12287281006@testacdload6.byoc.inintca.com>;tag=6jEUM0Q\r\nFrom: <sip:+17513338204@testacdload6.byoc.inintca.com:5060>;tag=41551\r\nCall-ID: 63e0c778-0cd5-402d-b894-fe97f1e770e0\r\nCSeq:"..., len = 1}, maddr_val = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 0}, method_val = {s = 0x207feebe0 <error: Cannot access memory at address 0x207feebe0>, len = 0}, lr_val = {s = 0x100000001 <error: Cannot access memory at address 0x100000001>, len = -904017816}, r2_val = {s = 0x7ffeca1dc694 "\003", len = 1}, gr_val = {s = 0x947f27 <tcp_current_req+7> " 100 Trying\r\nTo: <sip:12287281006@testacdload6.byoc.inintca.com>;tag=6jEUM0Q\r\nFrom: <sip:+17513338204@testacdload6.byoc.inintca.com:5060>;tag=41551\r\nCall-ID: 63e0c778-0cd5-402d-b894-fe97f1e770e0\r\nCSeq"..., len = 1963549292}, u_name = {{s = 0x696e690700000000 <error: Cannot access memory at address 0x696e690700000000>, len = 1633907822}, {s = 0x0, len = 0}, {s = 0x91bb80 <tmp> "pcv-homer-hep-nlb.us-east-1.inintca.com", len = 63783536}, {s = 0xd3736f36f5f44700 <error: Cannot access memory at address 0xd3736f36f5f44700>, len = 9731880}, {s = 0x1e35b70 "", len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x300000000 <error: Cannot access memory at address 0x300000000>, len = 3}, {s = 0x600000003 <error: Cannot access memory at address 0x600000003>, len = 0}, {s = 0x1e3a9b8 "", len = 16777217}}, u_val = {{s = 0x1 <error: Cannot access memory at address 0x1>, len = 31697168}, {s = 0xffffffff00000000 <error: Cannot access memory at address 0xffffffff00000000>, len = 0}, {s = 0x0, len = 0}, {s = 0x0, len = 0}, {s = 0x1 <error: Cannot access memory at address 0x1>, len = 0}, {s = 0x0, len = 63889568}, {s = 0xd3736f36f5f44700 <error: Cannot access memory at address 0xd3736f36f5f44700>, len = 63234960}, {s = 0x1e3a910 "", len = 0}, {s = 0x7f8f03cb2ec8 "\020\251\343\001", len = 9731880}, {s = 0x0, len = -904017816}}, u_params_no = 22378}
        next_hop = {user = {s = 0x1 <error: Cannot access memory at address 0x1>, len = -904017816}, passwd = {s = 0x0, len = 131159796}, host = {s = 0x2 <error: Cannot access memory at address 0x2>, len = 1}, port = {s = 0x7f8f03c8f7b0 "\002", len = 63889568}, params = {s = 0x7f8f03cb2ec8 "\020\251\343\001", len = 9731880}, headers = {s = 0x7ffeca1dc868 "\240\340\316\003\217\177", len = 32}, port_no = 57504, proto = 974, type = 32655, transport = {s = 0x7f8ebe71115b <t_check_status+1213> "E\204\366t\bHc[(E\210\064\034\205\300\017\205F\377\377\377\270\001", len = 0}, ttl = {s = 0x0, len = 63502256}, user_param = {s = 0x7f8f03cee0a0 "A\004", len = 9816536}, maddr = {s = 0x7f8f03cc2470 "\020", len = 16}, method = {s = 0x7f8ebe952240 <cmds+480> " ut\276\216\177", len = 16}, lr = {s = 0x7f8f03cee0a0 "A\004", len = 63889568}, r2 = {s = 0x430427 <do_action+8424> "A\211\307D\017\266#\351\307\337\377\377A\203\377\003\017\204<+", len = 0}, gr = {s = 0x7ffeca1dc9b0 "", len = 16}, transport_val = {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 63889568}, ttl_val = {s = 0x7f8f03c9fdd0 "\020", len = 2}, user_param_val = {s = 0x7f8f03cee0a0 "A\004", len = 63569896}, maddr_val = {s = 0x7f8f03cee0a0 "A\004", len = -904017456}, method_val = {s = 0x7f8f03ca0068 "\002", len = 63889568}, lr_val = {s = 0x4fb76c <pv_get_spec_value+253> "\205\300\017\205h\377\377\377H\213s`H\205\366\017\204[\377\377\377L\211\342H\211\357\350\245\305\374\377\351K\377\377\377L\213h\020M\205\355t\305H\213\025\347\251@", len = 63565416}, r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x14 <error: Cannot access memory at address 0x14>, len = 2}, u_name = {{s = 0x7f8f03ca0068 "\002", len = 63889568}, {s = 0x47f879 <eval_elem+407> "\205\300\017\204\262\004", len = 2}, {s = 0x7f8f03cee0a0 "A\004", len = 63567416}, {s = 0x7f8f03cee0a0 "A\004", len = 0}, {s = 0x437b76 <run_action_list+71> "\211Ņ\300u\a\203\r\225.M", len = 0}, {s = 0x4fb76c <pv_get_spec_value+253> "\205\300\017\205h\377\377\377H\213s`H\205\366\017\204[\377\377\377L\211\342H\211\357\350\245\305\374\377\351K\377\377\377L\213h\020M\205\355t\305H\213\025\347\251@", len = 9816470}, {s = 0x1 <error: Cannot access memory at address 0x1>, len = 0}, {s = 0x0, len = 63567416}, {s = 0x7f8f03cee0a0 "A\004", len = 9816470}, {s = 0x1 <error: Cannot access memory at address 0x1>, len = 5}}, u_val = {{s = 0x7f8ebf5f04c0 <cmds+384> "w\311>\277\216\177", len = 16}, {s = 0x7f8f03cee0a0 "A\004", len = 63889568}, {s = 0x430427 <do_action+8424> "A\211\307D\017\266#\351\307\337\377\377A\203\377\003\017\204<+", len = 0}, {s = 0x4 <error: Cannot access memory at address 0x4>, len = 63570024}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 63889568}, {s = 0x0, len = 0}, {s = 0x47f5af <eval_expr+404> "\213\035\033\271H", len = 9816448}, {s = 0x1 <error: Cannot access memory at address 0x1>, len = 3}, {s = 0x7f8f03ca00b8 "\001", len = 4}, {s = 0x7f8f03cee0a0 "A\004", len = 0}}, u_params_no = 62939}
        u = <optimized out>
        port = 0
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        model = <optimized out>
        val = {rs = {s = 0x95c9d8 <int2str_buf+152> "2", len = 1}, ri = 5, flags = 28}
        pve = <optimized out>
        name_s = {s = 0x0, len = 9550720}
        start = {tv_sec = 9816492, tv_usec = 0}
        aux_counter = 0
        __FUNCTION__ = "do_action"
#27 0x0000000000437b76 in run_action_list (a=<optimized out>, msg=0x7f8f03cee0a0) at action.c:172
        ret = -1
        t = 0x7f8f03ca79e0
#28 0x0000000000437eb7 in run_actions (a=<optimized out>, msg=<optimized out>) at action.c:137
        ret = <optimized out>
        msg = <optimized out>
        a = <optimized out>
        ret = <optimized out>
#29 0x0000000000433c21 in do_action (a=a@entry=0x7f8f03ca0578, msg=msg@entry=0x7f8f03cee0a0) at action.c:761
        increment = <optimized out>
        decrement = <optimized out>
        j = <optimized out>
        num_rows = 0
        val_s = {s = 0x1d <error: Cannot access memory at address 0x1d>, len = 0}
        cdb_reply = 0x3000100808160db
        num_cols = <optimized out>
        aux = {s = 0x1d <error: Cannot access memory at address 0x1d>, len = 0}
        i = <optimized out>
        it = <optimized out>
        avp_val = <optimized out>
        avp_name = {n = 29, s = {s = 0x1d <error: Cannot access memory at address 0x1d>, len = 0}}
        avp_type = 9920
        ret = -5
        v = <optimized out>
        sec = <optimized out>
        usec = <optimized out>
        to = <optimized out>
        p = <optimized out>
        tmp = <optimized out>
        new_uri = <optimized out>
        end = <optimized out>
        crt = <optimized out>
        len = <optimized out>
        i = <optimized out>
        user = 0
        expires = 0
        vals = {{s = 0x3000100808160db <error: Cannot access memory at address 0x3000100808160db>, len = 0}, {s = 0x682d72656d6f682d <error: Cannot access memory at address 0x682d72656d6f682d>, len = 1848471653}, {s = 0x312d747361652d73 <error: Cannot access memory at address 0x312d747361652d73>, len = 1768843527}, {s = 0x100006d6f6303 <error: Cannot access memory at address 0x100006d6f6303>, len = 835585}, {s = 0xa3200a04003a0000 <error: Cannot access memory at address 0xa3200a04003a0000>, len = 835795}}
        result = {s = 0x7f8f07fee320 <resbuf> "\b\027\344\001", len = 2}
        uri = {user = {s = 0xc6200a04003a0000 <error: Cannot access memory at address 0xc6200a04003a0000>, len = 835724}, passwd = {s = 0xf4200a04003a0000 <error: Cannot access memory at address 0xf4200a04003a0000>, len = 31}, host = {s = 0x0, len = 0}, port = {s = 0x0, len = 0}, params = {s = 0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, transport = {s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 134130752}, method = {s = 0xffffffffffffffb0 <error: Cannot access memory at address 0xffffffffffffffb0>, len = 10}, lr = {s = 0x3df <error: Cannot access memory at address 0x3df>, len = 4112}, r2 = {s = 0x7f8eb91c5f0e <gethostbyname3_context+174> "H\205\300\017\204\241\002", len = -904016520}, gr = {s = 0x0, len = 0}, transport_val = {s = 0x400 <error: Cannot access memory at address 0x400>, len = 31724848}, ttl_val = {s = 0x7f8f086226c0 "", len = 0}, user_param_val = {s = 0x7f8eb91c5f0e <gethostbyname3_context+174> "H\205\300\017\204\241\002", len = -904016456}, maddr_val = {s = 0x0, len = 0}, method_val = {s = 0x400 <error: Cannot access memory at address 0x400>, len = 31724848}, lr_val = {s = 0x7f8f086226c0 "", len = 0}, r2_val = {s = 0x1e36200 "\320z\343\001", len = 0}, gr_val = {s = 0x7ffeca1dc960 "\002", len = -904016376}, u_name = {{s = 0x7f8f03cbfe78 "\020", len = 2}, {s = 0x7f8ebe9528c0 <faked_req> "-\004", len = 63700824}, {s = 0x7f8ebe9528c0 <faked_req> "-\004", len = -1097520960}, {s = 0x437b76 <run_action_list+71> "\211Ņ\300u\a\203\r\225.M", len = -1}, {s = 0x7ffeca1dc9b0 "", len = 4096}, {s = 0x0, len = 2}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 134130752}, {s = 0xffffffffffffffb0 <error: Cannot access memory at address 0xffffffffffffffb0>, len = 10}, {s = 0x3df <error: Cannot access memory at address 0x3df>, len = 4112}, {s = 0x7f8f07cba62d <_int_malloc+1725> "D\213T$\030\351\204\373\377\377f\017\037\204", len = 8}}, u_val = {{s = 0x1000 <error: Cannot access memory at address 0x1000>, len = 134130752}, {s = 0x7 <error: Cannot access memory at address 0x7>, len = 0}, {s = 0x1dc4808 "ponse", len = 4144}, {s = 0x7f8f07cba62d <_int_malloc+1725> "D\213T$\030\351\204\373\377\377f\017\037\204", len = -80}, {s = 0x1000 <error: Cannot access memory at address 0x1000>, len = 257}, {s = 0x7 <error: Cannot access memory at address 0x7>, len = 0}, {s = 0x1dc4808 "ponse", len = 4144}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = -80}, {s = 0x40 <error: Cannot access memory at address 0x40>, len = 257}, {s = 0x8 <error: Cannot access memory at address 0x8>, len = 1}}, u_params_no = 18190}
        next_hop = {user = {s = 0x1d <error: Cannot access memory at address 0x1d>, len = 0}, passwd = {s = 0x7f8f03cee9a0 "\001", len = -1170520294}, host = {s = 0x7f8eba3b470e <tls_current_req+206> ";tag=759103\r\ncall-id: 57cbf66b-9b07-4cd8-a46f-e420743135be\r\nCSeq: 1 INVITE\r\nallow-events: conference, talk, hold\r\nContact:  <sip:+99529887555450@10.30.181.43:5061;transport=tls>\r\nx-phonesim-proxy-type"..., len = 5724012}, port = {s = 0x7f8f03cc2550 "\002", len = 63889568}, params = {s = 0x7ffeca1dcff4 "\035", len = 29}, headers = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 33188}, port_no = 0, proto = 0, type = ERROR_URI_T, transport = {s = 0x0, len = 2}, ttl = {s = 0x2 <error: Cannot access memory at address 0x2>, len = 63710544}, user_param = {s = 0x7f8eba3b470e <tls_current_req+206> ";tag=759103\r\ncall-id: 57cbf66b-9b07-4cd8-a46f-e420743135be\r\nCSeq: 1 INVITE\r\nallow-events: conference, talk, hold\r\nContact:  <sip:+99529887555450@10.30.181.43:5061;transport=tls>\r\nx-phonesim-proxy-type"..., len = 63891872}, maddr = {s = 0xa <error: Cannot access memory at address 0xa>, len = -1170520363}, method = {s = 0x0, len = -1170520306}, lr = {s = 0x57b45e <parse_to+2508> "H\211ËM0D\213d$$\351\023\372\377\377L\211\373@\204\377\017\205\037\023", len = 8}, r2 = {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 840831000}, gr = {s = 0x5d7280c5 <error: Cannot access memory at address 0x5d7280c5>, len = 808831000}, transport_val = {s = 0x7f8f03cee0a0 "A\004", len = 0}, ttl_val = {s = 0x7f8f03cee0a0 "A\004", len = 68}, user_param_val = {s = 0x7f8f03cee9a0 "\001", len = 63340480}, maddr_val = {s = 0x7f8f03cee0a0 "A\004", len = 63889568}, method_val = {s = 0x5416ff <parse_from_header+184> "A\213,$\203\375\377\017\204\201\001", len = 10}, lr_val = {s = 0x7f8f03cee0a0 "A\004", len = 63889568}, r2_val = {s = 0x7f8f03cee0a0 "A\004", len = -904015536}, gr_val = {s = 0x4f039b <pv_get_to_attr+66> "H\203\304\020[]A\\\303\061Ҿ\b", len = 63710544}, u_name = {{s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 63341216}, {s = 0x7f8f03cee0a0 "A\004", len = -904015536}, {s = 0x4fb76c <pv_get_spec_value+253> "\205\300\017\205h\377\377\377H\213s`H\205\366\017\204[\377\377\377L\211\342H\211\357\350\245\305\374\377\351K\377\377\377L\213h\020M\205\355t\305H\213\025\347\251@", len = 63337696}, {s = 0x7ffeca1dd230 "\a", len = 30}, {s = 0x0, len = 52}, {s = 0x7f8f03cee0a0 "A\004", len = 63889568}, {s = 0x47fce2 <eval_elem+1536> "H\205\300\017\204W\f", len = 2}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 63337696}, {s = 0x7f8f03cee0a0 "A\004", len = 63889568}, {s = 0x47fa56 <eval_elem+884> "\351\301\375\377\377A\274\373\377\377\377L\213- gH", len = 63889568}}, u_val = {{s = 0x7f8f03c67ad8 " {\306\003\217\177", len = -904015472}, {s = 0x7f8f03c67af0 "P\357\316\003\217\177", len = 63889568}, {s = 0x7f8f03cee0a0 "A\004", len = 63889568}, {s = 0x4e70f7 <set_var_value+1032> "H\211C\030H\205\300u\263L\213\025\201\360A", len = -1170520424}, {s = 0x33 <error: Cannot access memory at address 0x33>, len = 63340960}, {s = 0x7f8f03c68188 "N", len = -904015312}, {s = 0x4ec3f7 <pv_set_scriptvar+337> "H\205\300\017\205\362\376\377\377H\213\065\201\235A", len = 0}, {s = 0x7f8f07d2b414 <tsearch+148> "\205\300\211\305\017\204\226", len = 63897664}, {s = 0x33 <error: Cannot access memory at address 0x33>, len = 63889568}, {s = 0x7f8f03c68188 "N", len = -904015312}}, u_params_no = 46498}
        u = <optimized out>
        port = 145
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        model = <optimized out>
        val = {rs = {s = 0x0, len = 0}, ri = 0, flags = 0}
        pve = <optimized out>
        name_s = {s = 0x7ffeca1dd5dc "\376\177", len = -1189322591}
        start = {tv_sec = 31724848, tv_usec = 1024}
        aux_counter = 0
        __FUNCTION__ = "do_action"
#30 0x0000000000437b76 in run_action_list (a=<optimized out>, msg=0x7f8f03cee0a0) at action.c:172
        ret = -1
        t = 0x7f8f03ca0578
#31 0x0000000000437eb7 in run_actions (a=<optimized out>, msg=<optimized out>) at action.c:137
        ret = <optimized out>
        msg = <optimized out>
        a = <optimized out>
        ret = <optimized out>
#32 0x0000000000433c21 in do_action (a=a@entry=0x7f8f03c684e8, msg=msg@entry=0x7f8f03cee0a0) at action.c:761
        increment = <optimized out>
        decrement = <optimized out>
        j = <optimized out>
        num_rows = 949905709
        val_s = {s = 0x7ffeca1dd7b0 "\242J;\272\216\177", len = -982556768}
        cdb_reply = 0x5a8279995a827999
        num_cols = <optimized out>
        aux = {s = 0x7ffeca1dd7b0 "\242J;\272\216\177", len = -982556768}
        i = <optimized out>
        it = <optimized out>
        avp_val = <optimized out>
        avp_name = {n = -904013904, s = {s = 0x7ffeca1dd7b0 "\242J;\272\216\177", len = -982556768}}
        avp_type = 5100
        ret = -5
        v = <optimized out>
        sec = <optimized out>
        usec = <optimized out>
        to = <optimized out>
        p = <optimized out>
        tmp = <optimized out>
        new_uri = <optimized out>
        end = <optimized out>
        crt = <optimized out>
        len = <optimized out>
        i = <optimized out>
        user = 0
        expires = 0
        vals = {{s = 0x5a8279995a827999 <error: Cannot access memory at address 0x5a8279995a827999>, len = 1518500249}, {s = 0x5a8279995a827999 <error: Cannot access memory at address 0x5a8279995a827999>, len = 1518500249}, {s = 0x5a8279995a827999 <error: Cannot access memory at address 0x5a8279995a827999>, len = 1518500249}, {s = 0x5a8279995a827999 <error: Cannot access memory at address 0x5a8279995a827999>, len = 1518500249}, {s = 0x7f8ec4103d30 "\225\335]\021Iȉ\016P\361;\025\305~x\202INVITE sip:12287281027@testacdload27.byoc.inintca.com:5061;transport=TLS SIP/2.0\r\nTo:  <sip:12287281027@testacdload27.byoc.inintca.com:5061>\r\nFrom:  <sip:+99529887555450@testacdload27."..., len = -1179106260}}
        result = {s = 0x7f8f07fee320 <resbuf> "\b\027\344\001", len = 31678976}
        uri = {user = {s = 0x50f16739015517a <error: Cannot access memory at address 0x50f16739015517a>, len = -1175268082}, passwd = {s = 0x7f8ec40fde50 "", len = 1}, host = {s = 0x7f8ec40fd450 "", len = 1}, port = {s = 0x0, len = -1175265997}, params = {s = 0x7f8ec410f620 "\300\002\177", len = 1}, headers = {s = 0x7ffeca1dd63d "\177", len = -1005595648}, port_no = 16, proto = 0, type = ERROR_URI_T, transport = {s = 0x603d37df9c6a6d00 <error: Cannot access memory at address 0x603d37df9c6a6d00>, len = -904014544}, ttl = {s = 0x7f8eb9ee02c0 <aesni_256_cbc> "\253\001", len = 0}, user_param = {s = 0x7f8ec40fde50 "", len = -1005593000}, maddr = {s = 0x7ffeca1dd430 "\200\004", len = 1152}, method = {s = 0xb0465804d6353294 <error: Cannot access memory at address 0xb0465804d6353294>, len = -850239023}, lr = {s = 0xc632b617dcc2f602 <error: Cannot access memory at address 0xc632b617dcc2f602>, len = -850239023}, r2 = {s = 0xc632b617dcc2f602 <error: Cannot access memory at address 0xc632b617dcc2f602>, len = -641646315}, gr = {s = 0x8074aae7832c3c88 <error: Cannot access memory at address 0x8074aae7832c3c88>, len = -641646315}, transport_val = {s = 0x8074aae7832c3c88 <error: Cannot access memory at address 0x8074aae7832c3c88>, len = -363600210}, ttl_val = {s = 0x295ede701fadefec <error: Cannot access memory at address 0x295ede701fadefec>, len = -363600210}, user_param_val = {s = 0x295ede701fadefec <error: Cannot access memory at address 0x295ede701fadefec>, len = 657700734}, maddr_val = {s = 0x234b851bfd993558 <error: Cannot access memory at address 0x234b851bfd993558>, len = 657700734}, method_val = {s = 0x234b851bfd993558 <error: Cannot access memory at address 0x234b851bfd993558>, len = -1933545743}, lr_val = {s = 0x4478326d969a493c <error: Cannot access memory at address 0x4478326d969a493c>, len = -1933545743}, r2_val = {s = 0x4478326d969a493c <error: Cannot access memory at address 0x4478326d969a493c>, len = 1477901230}, gr_val = {s = 0x91a2dafdb27578fc <error: Cannot access memory at address 0x91a2dafdb27578fc>, len = 1477901230}, u_name = {{s = 0x91a2dafdb27578fc <error: Cannot access memory at address 0x91a2dafdb27578fc>, len = -1904676934}, {s = 0x4547ebaa5bd97bc1 <error: Cannot access memory at address 0x4547ebaa5bd97bc1>, len = -1904676934}, {s = 0x4547ebaa5bd97bc1 <error: Cannot access memory at address 0x4547ebaa5bd97bc1>, len = 1559877674}, {s = 0xd647705ccbf6b0c <error: Cannot access memory at address 0xd647705ccbf6b0c>, len = 1559877674}, {s = 0xd647705ccbf6b0c <error: Cannot access memory at address 0xd647705ccbf6b0c>, len = 728198814}, {s = 0xbfd35f277bde34ce <error: Cannot access memory at address 0xbfd35f277bde34ce>, len = 728198814}, {s = 0xbfd35f277bde34ce <error: Cannot access memory at address 0xbfd35f277bde34ce>, len = 1144501740}, {s = 0x6863923b80b41f21 <error: Cannot access memory at address 0x6863923b80b41f21>, len = 1144501740}, {s = 0x6863923b80b41f21 <error: Cannot access memory at address 0x6863923b80b41f21>, len = 420512050}, {s = 0x73eedbee4b49eedf <error: Cannot access memory at address 0x73eedbee4b49eedf>, len = -859147385}}, u_val = {{s = 0x93799f4ce52cf70d <error: Cannot access memory at address 0x93799f4ce52cf70d>, len = 1131251580}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 1569454996}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 1352090846}, {s = 0x6c76f351a3cbc858 <error: Cannot access memory at address 0x6c76f351a3cbc858>, len = -904013904}, {s = 0x7ffeca1dd650 "\260ʕ", len = -1001986820}, {s = 0x7ffeca1dd860 "\242J;\272\216\177", len = -1001986848}, {s = 0x7f8eb9bf9c5b <SHA1_Final+171> "\213\003H\211\301H\211\302H\301\351\030\210U\003\210M", len = -982556768}, {s = 0x7ffeca1dd6cc "\216\177", len = -904014132}, {s = 0x7f8eb9b83aa2 <EVP_DigestFinal_ex+82> "D\211\340[]A\\\303H\215\065\336\a\017", len = -1005607712}, {s = 0x7ffeca1dd860 "\242J;\272\216\177", len = -904014132}}, u_params_no = 6420}
        next_hop = {user = {s = 0x7ffeca1dd7b0 "\242J;\272\216\177", len = -982556768}, passwd = {s = 0x95cab0 <shm_block> "", len = -1005607712}, host = {s = 0x95cab0 <shm_block> "", len = -1000729888}, port = {s = 0x95cab0 <shm_block> "", len = -1182754235}, params = {s = 0x7f8ec45a12e0 "\200 \371Î\177", len = -997681528}, headers = {s = 0x1 <error: Cannot access memory at address 0x1>, len = -1000729960}, port_no = 51888, proto = 149, type = ERROR_URI_T, transport = {s = 0x7f8eb9809a45 <os_free+93> "H\213\065\324\343 ", len = -1000729960}, ttl = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 9816752}, user_param = {s = 0x7f8eb9809a45 <os_free+93> "H\213\065\324\343 ", len = 1}, maddr = {s = 0x7f8ec4a51000 "", len = 1}, method = {s = 0x7f8ec56f1b90 "\001", len = 9816752}, lr = {s = 0x7f8ec4061190 "`\025\031\272\216\177", len = 9816752}, r2 = {s = 0x7f8ec40bdfc8 "", len = 9816752}, gr = {s = 0x7f8eb9809a45 <os_free+93> "H\213\065\324\343 ", len = -1005854776}, transport_val = {s = 0x7f8ec51528b0 "\004", len = -1005595648}, ttl_val = {s = 0x7f8ec4a51000 "", len = 9816752}, user_param_val = {s = 0x7f8eb9809a45 <os_free+93> "H\213\065\324\343 ", len = -995815424}, maddr_val = {s = 0x0, len = 9816752}, method_val = {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 0}, lr_val = {s = 0x7f8ec4a51000 "", len = -1005595648}, r2_val = {s = 0x7f8ec40fde50 "", len = 0}, gr_val = {s = 0x7f8eba3b4867 <tls_current_req+551> "061;branch=z9hG4bKfe1356404580455cb6102c7505b484d7\r\n\r\nv=0\r\no=- 242301173 3776777986 IN IP4 10.30.207.33\r\ns= \r\nc=IN IP4 10.30.207.33\r\nt=0 0\r\nm=audio 31834 RTP/SAVP 96 0 97 101 102 103\r\na=rtpmap:96 opus"..., len = 6}, u_name = {{s = 0x7f8eba3b486b <tls_current_req+555> "branch=z9hG4bKfe1356404580455cb6102c7505b484d7\r\n\r\nv=0\r\no=- 242301173 3776777986 IN IP4 10.30.207.33\r\ns= \r\nc=IN IP4 10.30.207.33\r\nt=0 0\r\nm=audio 31834 RTP/SAVP 96 0 97 101 102 103\r\na=rtpmap:96 opus/480"..., len = -1170519390}, {s = 0x7f8eba3b4831 <tls_current_req+497> "SIP/2.0/TLS phonesim-container-phonesim-10-30-181-43:5061;branch=z9hG4bKfe1356404580455cb6102c7505b484d7\r\n\r\nv=0\r\no=- 242301173 3776777986 IN IP4 10.30.207.33\r\ns= \r\nc=IN IP4 10.30.207.33\r\nt=0 0\r\nm=audi"..., len = -18}, {s = 0x55d47f <parse_via+14719> "I\211\304H\205\300D\213\\$DL\213L$HD\017\266T$P\017\204\254\254", len = 63891872}, {s = 0x7f8ec40fc6a0 "\003\003", len = -1005567568}, {s = 0x7f8ec40fd400 "\003\003", len = 20}, {s = 0x7f8f03cef0d0 "\001", len = 63893712}, {s = 0x7f8eba3b486b <tls_current_req+555> "branch=z9hG4bKfe1356404580455cb6102c7505b484d7\r\n\r\nv=0\r\no=- 242301173 3776777986 IN IP4 10.30.207.33\r\ns= \r\nc=IN IP4 10.30.207.33\r\nt=0 0\r\nm=audio 31834 RTP/SAVP 96 0 97 101 102 103\r\na=rtpmap:96 opus/480"..., len = 1152}, {s = 0x7f8eba3b486b <tls_current_req+555> "branch=z9hG4bKfe1356404580455cb6102c7505b484d7\r\n\r\nv=0\r\no=- 242301173 3776777986 IN IP4 10.30.207.33\r\ns= \r\nc=IN IP4 10.30.207.33\r\nt=0 0\r\nm=audio 31834 RTP/SAVP 96 0 97 101 102 103\r\na=rtpmap:96 opus/480"..., len = -1170520320}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = -1005523560}, {s = 0x948000 <tcp_current_req+224> "SIP/2.0/TCP 10.32.42.80:5060;branch=z9hG4bK2ad8.57eb194.0\r\nVia: SIP/2.0/UDP 10.32.243.183:6060;branch=z9hG4bK2ad8.ace856f1.0\r\nDate: Fri, 06 Sep 2019 16:59:46 GMT\r\nUser-Agent: GENESYS-SIPSERVICE/1.0.0."..., len = 6}}, u_val = {{s = 0x54a303 <parse_cseq+1251> "H\205\300uT\351}\001", len = 63889568}, {s = 0x7f8eba3b4831 <tls_current_req+497> "SIP/2.0/TLS phonesim-container-phonesim-10-30-181-43:5061;branch=z9hG4bKfe1356404580455cb6102c7505b484d7\r\n\r\nv=0\r\no=- 242301173 3776777986 IN IP4 10.30.207.33\r\ns= \r\nc=IN IP4 10.30.207.33\r\nt=0 0\r\nm=audi"..., len = -1170519390}, {s = 0x7f8f03ceee90 "\001", len = 0}, {s = 0x1 <error: Cannot access memory at address 0x1>, len = 63893712}, {s = 0x550ca3 <get_hdr_field+1619> "H\211\303A\203?\377\017\204\245\a", len = 4}, {s = 0x9480e3 <tcp_current_req+451> "", len = 0}, {s = 0x3cee0a0 <error: Cannot access memory at address 0x3cee0a0>, len = 9584808}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = -999316664}, {s = 0x947ffb <tcp_current_req+219> "Via: SIP/2.0/TCP 10.32.42.80:5060;branch=z9hG4bK2ad8.57eb194.0\r\nVia: SIP/2.0/UDP 10.32.243.183:6060;branch=z9hG4bK2ad8.ace856f1.0\r\nDate: Fri, 06 Sep 2019 16:59:46 GMT\r\nUser-Agent: GENESYS-SIPSERVICE/1"..., len = 0}, {s = 0x9480e3 <tcp_current_req+451> "", len = 0}}, u_params_no = 18476}
        u = <optimized out>
        port = 0
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        model = <optimized out>
        val = {rs = {s = 0xda827999389e692d <error: Cannot access memory at address 0xda827999389e692d>, len = 1518500249}, ri = 949905709, flags = -628983399}
        pve = <optimized out>
        name_s = {s = 0x0, len = 131399955}
        start = {tv_sec = 8202997763555070956, tv_usec = -7163928902072702148}
        aux_counter = 0
        __FUNCTION__ = "do_action"
#33 0x0000000000437b76 in run_action_list (a=a@entry=0x7f8f03c67078, msg=msg@entry=0x7f8f03cee0a0) at action.c:172
        ret = -1
        t = 0x7f8f03c684e8
#34 0x000000000043802a in run_actions (msg=0x7f8f03cee0a0, a=0x7f8f03c67078) at action.c:137
        ret = <optimized out>
        msg = 0x7f8f03cee0a0
        a = 0x7f8f03c67078
        ret = <optimized out>
#35 run_top_route (a=0x7f8f03c67078, msg=msg@entry=0x7f8f03cee0a0) at action.c:214
        bk_action_flags = 0
        bk_rec_lev = 0
        ret = <optimized out>
        ctx = 0x0
        __FUNCTION__ = "run_top_route"
#36 0x000000000043ef2e in receive_msg (buf=0x7f8eba3b4640 <tls_current_req> "INVITE sip:12287281027@testacdload27.byoc.inintca.com:5061;transport=TLS SIP/2.0\r\nTo:  <sip:12287281027@testacdload27.byoc.inintca.com:5061>\r\nFrom:  <sip:+99529887555450@testacdload27.byoc.inintca.com"..., len=<optimized out>, len@entry=1122, rcv_info=rcv_info@entry=0x7ffeca1ddb10, existing_context=existing_context@entry=0x0, flags=flags@entry=0) at receive.c:209
        ctx = 0x7f8f03cef230
        msg = 0x7f8f03cee0a0
        start = {tv_sec = 140251151451808, tv_usec = 140250981855039}
        rc = 3
        in_buff = {s = 0x7f8eba3b4640 <tls_current_req> "INVITE sip:12287281027@testacdload27.byoc.inintca.com:5061;transport=TLS SIP/2.0\r\nTo:  <sip:12287281027@testacdload27.byoc.inintca.com:5061>\r\nFrom:  <sip:+99529887555450@testacdload27.byoc.inintca.com"..., len = 1122}
        __FUNCTION__ = "receive_msg"
#37 0x00007f8eba1ad11e in tcp_handle_req (_max_msg_chunks=<optimized out>, con=<optimized out>, req=0x7f8eba3b4640 <tls_current_req>) at ../../net/proto_tcp/tcp_common.h:411
        local_rcv = {src_ip = {af = 2, len = 4, u = {addrl = {2048780306, 0}, addr32 = {2048780306, 0, 0, 0}, addr16 = {59410, 31261, 0, 0, 0, 0, 0, 0}, addr = "\022\350\035z", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {1344937994, 0}, addr32 = {1344937994, 0, 0, 0}, addr16 = {8202, 20522, 0, 0, 0, 0, 0, 0}, addr = "\n *P", '\000' <repeats 11 times>}}, src_port = 60014, dst_port = 5061, proto = 3, proto_reserved1 = 1279506660, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "\352n\022\350\035z\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 28394, sin_addr = {s_addr = 2048780306}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 28394, 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}}, bind_address = 0x7f8f03c97c10}
        msg_buf = <optimized out>
        msg_len = <optimized out>
        c = 118 'v'
        size = 0
#38 tls_read_req (con=0x7f8ec40fc510, bytes_read=0x7ffeca1ddc20) at proto_tls.c:600
        bytes = <optimized out>
        total_bytes = 1122
        req = <optimized out>
        data = <optimized out>
        __FUNCTION__ = "tls_read_req"
#39 0x00000000005f5247 in handle_io (event_type=1, idx=2, fm=<optimized out>) at net/net_tcp_proc.c:241
        con = <optimized out>
        ret = 0
        n = <optimized out>
        rw = <optimized out>
        response = {9584996, 139641264990920}
        s = 0
        resp = <optimized out>
#40 io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:280
        ret = <optimized out>
        i = <optimized out>
        e = <optimized out>
        ep_event = {events = 0, data = {ptr = 0x0, fd = 0, u32 = 0, u64 = 0}}
        fd = <optimized out>
        n = 1
        r = 2
#41 tcp_worker_proc_loop () at net/net_tcp_proc.c:386
        __FUNCTION__ = "tcp_worker_proc_loop"
#42 0x0000000000603918 in tcp_start_processes (chd_rank=chd_rank@entry=0x924164 <chd_rank>, startup_done=startup_done@entry=0x7f8ec3feeac8) at net/net_tcp.c:1903
        r = 7
        reader_fd = {113, 115}
        pid = <optimized out>
        __FUNCTION__ = "tcp_start_processes"
#43 0x000000000041c1d1 in main_loop () at main.c:788
        startup_done = 0x7f8ec3feeac8
        rc = <optimized out>
        chd_rank = 24
#44 main (argc=<optimized out>, argv=<optimized out>) at main.c:1439
        cfg_stream = <optimized out>
        c = <optimized out>
        r = 0
        tmp = 0x7ffeca1deecf ""
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x653a38 "f:cCm:M:b:l:n:N:rRvdDFEVhw:t:u:g:P:G:W:o:"
        ret = -1
        seed = 4040934784
        rfd = <optimized out>
        __FUNCTION__ = "main"

[New LWP 13139]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/local/sbin/opensips -P /var/run/genesys/opensips-forward.pid -f /home/pcv-'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00007f2c29c8fb85 in aesni_ecb_encrypt () from /lib64/libcrypto.so.1.1

Thread 1 (Thread 0x7f2c78812740 (LWP 13139)):
#0  0x00007f2c29c8fb85 in aesni_ecb_encrypt () from /lib64/libcrypto.so.1.1
No symbol table info available.
#1  0x00007f2c29d77237 in aesni_ecb_cipher () from /lib64/libcrypto.so.1.1
No symbol table info available.
#2  0x00007f2c29d8625e in EVP_EncryptUpdate () from /lib64/libcrypto.so.1.1
No symbol table info available.
#3  0x00007f2c29dc2797 in ctr_update () from /lib64/libcrypto.so.1.1
No symbol table info available.
#4  0x00007f2c29dc3b68 in drbg_ctr_generate () from /lib64/libcrypto.so.1.1
No symbol table info available.
#5  0x00007f2c29dc5b69 in RAND_DRBG_generate () from /lib64/libcrypto.so.1.1
No symbol table info available.
#6  0x00007f2c29dc5e02 in RAND_DRBG_bytes () from /lib64/libcrypto.so.1.1
No symbol table info available.
#7  0x00007f2c2a11d71e in tls1_enc () from /lib64/libssl.so.1.1
No symbol table info available.
#8  0x00007f2c2a11a9c0 in do_ssl3_write () from /lib64/libssl.so.1.1
No symbol table info available.
#9  0x00007f2c2a11b0c1 in ssl3_write_bytes () from /lib64/libssl.so.1.1
No symbol table info available.
#10 0x00007f2c2a12fccc in ssl_write_internal () from /lib64/libssl.so.1.1
No symbol table info available.
#11 0x00007f2c2a12fee5 in SSL_write () from /lib64/libssl.so.1.1
No symbol table info available.
#12 0x00007f2c2a38eb86 in tls_write (c=c@entry=0x7f2c34c35280, buf=buf@entry=0x7f2c73ed1550, len=len@entry=373, poll_events=poll_events@entry=0x7ffca55d34e4, fd=<optimized out>) at ../tls_mgm/tls_conn_server.h:529
        ret = <optimized out>
        err = <optimized out>
        ssl = 0x7f2c35300920
#13 0x00007f2c2a39fc6d in tls_blocking_write (api=0x7f2c2a5b47a0 <tls_mgm_api>, api=0x7f2c2a5b47a0 <tls_mgm_api>, t_dst=0x0, len=373, buf=0x7f2c73ed1550 "SIP/2.0 100 Trying\r\nTo:  <sip:12287281077@testacdload77.byoc.inintca.com:5061>\r\nFrom:  <sip:+903083460804@testacdload77.byoc.inintca.com:5061>;tag=139713\r\ncall-id: 1a17c797-b66e-4fc7-9bcd-1d377685d0fd"..., fd=<optimized out>, c=0x7f2c34c35280) at ../tls_mgm/tls_conn_server.h:603
        written = 0
        timeout = <optimized out>
        pf = {fd = 188, events = 0, revents = 0}
        n = 0
        retries = 0
#14 proto_tls_send (send_sock=0x7f2c73e87c10, buf=<optimized out>, len=<optimized out>, to=<optimized out>, id=<optimized out>) at proto_tls.c:475
        c = 0x7f2c34c35280
        ip = {af = 2, len = 4, u = {addrl = {2048780306, 0}, addr32 = {2048780306, 0, 0, 0}, addr16 = {59410, 31261, 0, 0, 0, 0, 0, 0}, addr = "\022\350\035z", '\000' <repeats 11 times>}}
        fd = 188
        n = <optimized out>
        __FUNCTION__ = "proto_tls_send"
#15 0x00007f2c33c24a73 in msg_send (msg=0x0, len=<optimized out>, buf=0x7f2c73ed1550 "SIP/2.0 100 Trying\r\nTo:  <sip:12287281077@testacdload77.byoc.inintca.com:5061>\r\nFrom:  <sip:+903083460804@testacdload77.byoc.inintca.com:5061>;tag=139713\r\ncall-id: 1a17c797-b66e-4fc7-9bcd-1d377685d0fd"..., id=<optimized out>, to=0x7ffca55d35a0, proto=<optimized out>, send_sock=0x7f2c73e87c10) at ../../forward.h:123
        out_buff = {s = 0x7f2c73ed1550 "SIP/2.0 100 Trying\r\nTo:  <sip:12287281077@testacdload77.byoc.inintca.com:5061>\r\nFrom:  <sip:+903083460804@testacdload77.byoc.inintca.com:5061>;tag=139713\r\ncall-id: 1a17c797-b66e-4fc7-9bcd-1d377685d0fd"..., len = 373}
#16 sl_send_reply_helper (msg=<optimized out>, code=100, text=<optimized out>) at sl_funcs.c:192
        buf = {s = 0x7f2c73ed1550 "SIP/2.0 100 Trying\r\nTo:  <sip:12287281077@testacdload77.byoc.inintca.com:5061>\r\nFrom:  <sip:+903083460804@testacdload77.byoc.inintca.com:5061>;tag=139713\r\ncall-id: 1a17c797-b66e-4fc7-9bcd-1d377685d0fd"..., len = 373}
        dset = <optimized out>
        dset_len = 32764
        dummy_bm = {to_tag_val = {s = 0x0, len = 0}}
        backup_mhomed = 0
        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}}
        text = <optimized out>
        msg = <optimized out>
        code = 100
#17 0x00007f2c33c26fcb in w_sl_send_reply (msg=0x7f2c73ece148, str1=<optimized out>, str2=<optimized out>) at sl.c:242
        code_s = {s = 0x7f2c73e7f2b0 "Trying", len = 6}
        code_i = <optimized out>
#18 0x0000000000430427 in do_action (a=a@entry=0x7f2c73e7f348, msg=msg@entry=0x7f2c73ece148) at action.c:1866
        increment = <optimized out>
        decrement = <optimized out>
        j = <optimized out>
        num_rows = 17
        val_s = {s = 0x7f2c73e63a10 "\002", len = 2}
        cdb_reply = 0x7ffca55d3a20
        num_cols = <optimized out>
        aux = {s = 0x7f2c73e63a10 "\002", len = 2}
        i = <optimized out>
        it = <optimized out>
        avp_val = <optimized out>
        avp_name = {n = 1944467984, s = {s = 0x7f2c73e63a10 "\002", len = 2}}
        avp_type = 0
        ret = -5
        v = <optimized out>
        sec = <optimized out>
        usec = <optimized out>
        to = <optimized out>
        p = <optimized out>
        tmp = <optimized out>
        new_uri = <optimized out>
        end = <optimized out>
        crt = <optimized out>
        len = <optimized out>
        i = <optimized out>
        user = 0
        expires = 0
        vals = {{s = 0x7ffca55d3a20 "", len = 2011824640}, {s = 0x7ffcfbad8001 <error: Cannot access memory at address 0x7ffcfbad8001>, len = -1520616928}, {s = 0x7ffca55d3a20 "", len = -1520616928}, {s = 0x7ffca55d3a20 "", len = -1520616923}, {s = 0x7ffca55d3a31 ":\346s,\177", len = -1520616928}}
        result = {s = 0x100006d6f6303 <error: Cannot access memory at address 0x100006d6f6303>, len = 835585}
        uri = {user = {s = 0x7ffca55d3a31 ":\346s,\177", len = 0}, passwd = {s = 0x0, len = 0}, host = {s = 0x0, len = 0}, port = {s = 0x73e40cd8 <error: Cannot access memory at address 0x73e40cd8>, len = 1944904008}, params = {s = 0x0, len = 0}, headers = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 5374945}, port_no = 65535, proto = 65535, type = 4294967295, transport = {s = 0x0, len = -1520617296}, ttl = {s = 0x4fb78c <pv_get_spec_value+285> "\351K\377\377\377L\213h\020M\205\355t\305H\213\025\347\251@", len = -1}, user_param = {s = 0x7ffca55d3a00 "", len = 30}, maddr = {s = 0x7f2c781d7100 <_IO_strn_jumps> "", len = 0}, method = {s = 0x7f2c73ece148 "\246\b", len = 0}, lr = {s = 0x2 <error: Cannot access memory at address 0x2>, len = 1}, r2 = {s = 0x553baf <set_dst_uri+94> "H\211\203X\002", len = 0}, gr = {s = 0x7f2c2dd12909 <pv_get_stat+515> "\211C\020Lc\330M\205\333\017\210\177\004", len = -1520617328}, transport_val = {s = 0x7f2c345f9248 "\360\027\217\064,\177", len = 2}, ttl_val = {s = 0x7f2c2dd12909 <pv_get_stat+515> "\211C\020Lc\330M\205\333\017\210\177\004", len = -998}, user_param_val = {s = 0x7f2c3449da80 "\002", len = -1520616608}, maddr_val = {s = 0x7f2c345f8e40 "\220\233\357\064,\177", len = 2}, method_val = {s = 0x7f2c77e7f7af <snprintf+143> "H\213T$\030dH3\024%(", len = 32}, lr_val = {s = 0x7ffca55d3a50 "\003", len = -1520617232}, r2_val = {s = 0x29 <error: Cannot access memory at address 0x29>, len = -1520617232}, gr_val = {s = 0x7ffca55d3a50 "\003", len = 1026}, u_name = {{s = 0x7f2c781eb06c <ns_name_uncompress+76> "\203\370\377t'H\213\214$\b\001", len = 1986228241}, {s = 0x7f2c73e638a8 "\266\004", len = 1944904008}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 1944467904}, {s = 0x7f2c73ece148 "\246\b", len = 3}, {s = 0x4fb76c <pv_get_spec_value+253> "\205\300\017\205h\377\377\377H\213s`H\205\366\017\204[\377\377\377L\211\342H\211\357\350\245\305\374\377\351K\377\377\377L\213h\020M\205\355t\305H\213\025\347\251@", len = 1633907822}, {s = 0x7ffca55d3b10 "", len = 30}, {s = 0x0, len = 11}, {s = 0x7f2c73ece148 "\246\b", len = 3}, {s = 0x47fce2 <eval_elem+1536> "H\205\300\017\204W\f", len = 0}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 2}}, u_val = {{s = 0x7f2c2e6a1034 <ds_select_dst+6058> "\205\300I\213|$\b\017\205\344\352\377\377L\213\237", <incomplete sequence \310>, len = 1944314664}, {s = 0x7ffca55d3ae0 "", len = -1520616736}, {s = 0x7f2c2dd12909 <pv_get_stat+515> "\211C\020Lc\330M\205\333\017\210\177\004", len = 0}, {s = 0x1 <error: Cannot access memory at address 0x1>, len = -1520616928}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 1}, {s = 0x7f2c345f9238 "\360\027\217\064,\177", len = 9816527}, {s = 0xa <error: Cannot access memory at address 0xa>, len = 1073741824}, {s = 0xbb72a969dd690f00 <error: Cannot access memory at address 0xbb72a969dd690f00>, len = 9728}, {s = 0x7ffca55d4139 "\004", len = -1520615111}, {s = 0x0, len = -1520615168}}, u_params_no = 3}
        next_hop = {user = {s = 0x7f2c73e63a10 "\002", len = 2}, passwd = {s = 0x7f2c73ece148 "\246\b", len = -1520616656}, host = {s = 0x3 <error: Cannot access memory at address 0x3>, len = -1520616688}, port = {s = 0x7 <error: Cannot access memory at address 0x7>, len = 5246387}, params = {s = 0x7ffca55d3c60 " =]\245\374\177", len = 7}, headers = {s = 0x2 <error: Cannot access memory at address 0x2>, len = 10737418}, port_no = 57672, proto = 29676, type = 32556, transport = {s = 0x47faf9 <eval_elem+1047> "H\205\333t\004D\211k\020E1\344E\205\355A\017\225\304\351j\374\377\377D\213\254$\200", len = 0}, ttl = {s = 0x7f2c293b5f0e <gethostbyname3_context+174> "H\205\300\017\204\241\002", len = -1520616712}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x400 <error: Cannot access memory at address 0x400>, len = 12924208}, method = {s = 0x7f2c788126c0 "", len = 0}, lr = {s = 0xc800f0 "0\231", <incomplete sequence \307>, len = 1944915344}, r2 = {s = 0x7ffca55d36a0 ":S\201\200", len = 0}, gr = {s = 0x0, len = 0}, transport_val = {s = 0x0, len = 0}, ttl_val = {s = 0x7f2c73e60390 "\002", len = 0}, user_param_val = {s = 0x7f2c73e7e3e8 "\020", len = 2}, maddr_val = {s = 0x7f2c73ece148 "\246\b", len = 1944577224}, method_val = {s = 0x7f2c73ece148 "\246\b", len = 0}, lr_val = {s = 0x437b76 <run_action_list+71> "\211Ņ\300u\a\203\r\225.M", len = 1944904008}, r2_val = {s = 0x7f2c73e7f000 "\020", len = 2}, gr_val = {s = 0x7f2c73ece148 "\246\b", len = 1944580320}, u_name = {{s = 0x7f2c73ece148 "\246\b", len = 0}, {s = 0x437b76 <run_action_list+71> "\211Ņ\300u\a\203\r\225.M", len = 0}, {s = 0x47fa56 <eval_elem+884> "\351\301\375\377\377A\274\373\377\377\377L\213- gH", len = 1944672688}, {s = 0x0, len = 2}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 1944580320}, {s = 0x7f2c73ece148 "\246\b", len = 0}, {s = 0x47fa56 <eval_elem+884> "\351\301\375\377\377A\274\373\377\377\377L\213- gH", len = 2}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 1944672688}, {s = 0x7f2c73ece148 "\246\b", len = 0}, {s = 0x47fa56 <eval_elem+884> "\351\301\375\377\377A\274\373\377\377\377L\213- gH", len = 257}}, u_val = {{s = 0x4 <error: Cannot access memory at address 0x4>, len = 0}, {s = 0x0, len = 0}, {s = 0x7f2c00000000 <error: Cannot access memory at address 0x7f2c00000000>, len = -1520616160}, {s = 0x4ec2e9 <pv_set_scriptvar+67> "H\205\300\017\204\016\001", len = 708445397}, {s = 0x3 <error: Cannot access memory at address 0x3>, len = 1944577224}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 1944904008}, {s = 0x0, len = 0}, {s = 0x47f5af <eval_expr+404> "\213\035\033\271H", len = 1944671280}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 1944580320}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 1944904008}}, u_params_no = 0}
        u = <optimized out>
        port = 26990
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        model = <optimized out>
        val = {rs = {s = 0x11 <error: Cannot access memory at address 0x11>, len = 778744078}, ri = -1520617296, flags = 32764}
        pve = <optimized out>
        name_s = {s = 0xa3200a0400330000 <error: Cannot access memory at address 0xa3200a0400330000>, len = 835795}
        start = {tv_sec = -4170322242645590016, tv_usec = 281479272513676}
        aux_counter = 1633907822
        __FUNCTION__ = "do_action"
#19 0x0000000000437b76 in run_action_list (a=<optimized out>, msg=msg@entry=0x7f2c73ece148) at action.c:172
        ret = -1
        t = 0x7f2c73e7f348
#20 0x0000000000434f89 in do_action (a=a@entry=0x7f2c73e7f428, msg=msg@entry=0x7f2c73ece148) at action.c:1124
        increment = <optimized out>
        decrement = <optimized out>
        j = <optimized out>
        num_rows = 0
        val_s = {s = 0x35d <error: Cannot access memory at address 0x35d>, len = 1260}
        cdb_reply = 0x0
        num_cols = <optimized out>
        aux = {s = 0x35d <error: Cannot access memory at address 0x35d>, len = 1260}
        i = <optimized out>
        it = <optimized out>
        avp_val = <optimized out>
        avp_name = {n = 861, s = {s = 0x35d <error: Cannot access memory at address 0x35d>, len = 1260}}
        avp_type = 0
        ret = 1
        v = 1
        sec = <optimized out>
        usec = <optimized out>
        to = <optimized out>
        p = <optimized out>
        tmp = <optimized out>
        new_uri = <optimized out>
        end = <optimized out>
        crt = <optimized out>
        len = <optimized out>
        i = <optimized out>
        user = 0
        expires = 0
        vals = {{s = 0x0, len = 12924240}, {s = 0x7fffffff <error: Cannot access memory at address 0x7fffffff>, len = 992}, {s = 0xc5392f "\377&", len = -580317440}, {s = 0x3e0 <error: Cannot access memory at address 0x3e0>, len = 13147168}, {s = 0x0, len = 0}}
        result = {s = 0xc8f9c7 "", len = 2011845090}
        uri = {user = {s = 0x2 <error: Cannot access memory at address 0x2>, len = 12924296}, passwd = {s = 0x0, len = 2011844827}, host = {s = 0x7f2c77ea4470 <flush_cleanup> "H\213\005\031\204\063", len = -580317440}, port = {s = 0x0, len = 13147168}, params = {s = 0x0, len = 2012328980}, headers = {s = 0x0, len = 12730656}, port_no = 16184, proto = 42333, type = 32764, transport = {s = 0x7f2c77f41540 <known_compare> "H9\367t\vH\213\066H\213?\351\360\221\360\377\061\300\303\017\037", len = 9550720}, ttl = {s = 0x7ffca55d4010 "\200\377\377\377\377\377\377\377", len = -1520615552}, user_param = {s = 0xbb72a969dd690f00 <error: Cannot access memory at address 0xbb72a969dd690f00>, len = -1520615624}, maddr = {s = 0x7f2c788126c0 "", len = 13107440}, method = {s = 0x7f2c781de320 <resbuf> "\b", <incomplete sequence \305>, len = 12924208}, lr = {s = 0x400 <error: Cannot access memory at address 0x400>, len = -1520615316}, r2 = {s = 0x7f2c293b6a55 <_nss_dns_gethostbyname_r+101> "H\203\304 L\211\347\211D$\b\350\353\344\377\377\213D$\bH\203\304\030[]A\\A]A^A_\303\017\037\204", len = 2021729984}, gr = {s = 0x7ffca55d406c "", len = 0}, transport_val = {s = 0x7f2c293b6a65 <_nss_dns_gethostbyname_r+117> "\213D$\bH\203\304\030[]A\\A]A^A_\303\017\037\204", len = -1520615416}, ttl_val = {s = 0xbb72a969dd690f00 <error: Cannot access memory at address 0xbb72a969dd690f00>, len = 2012898908}, user_param_val = {s = 0x7ffca55d406c "", len = 1}, maddr_val = {s = 0x7f2c781de320 <resbuf> "\b", <incomplete sequence \305>, len = 1}, method_val = {s = 0x91bb80 <tmp> "pcv-homer-hep-nlb.us-east-1.inintca.com", len = -128}, lr_val = {s = 0x7f2c77f32020 <gethostbyname_r@@GLIBC_2.2.5+608> "\213T$D\203\372\001\017\206\033\001", len = 12491344}, r2_val = {s = 0x7f2c788126c0 "", len = -1520615408}, gr_val = {s = 0x7ffca55d4008 <incomplete sequence \360>, len = -1520615312}, u_name = {{s = 0xc800f0 "0\231", <incomplete sequence \307>, len = 0}, {s = 0xbb72a969dd690f00 <error: Cannot access memory at address 0xbb72a969dd690f00>, len = 2015226848}, {s = 0xc800f0 "0\231", <incomplete sequence \307>, len = -128}, {s = 0x0, len = 2015224608}, {s = 0xc800f0 "0\231", <incomplete sequence \307>, len = 0}, {s = 0x7f2c77f40113 <context_free+51> "dD\211e", len = 9550720}, {s = 0x7ffca55d4070 " \343\035x,\177", len = -1520615316}, {s = 0x7f2c77f31565 <gethostbyname+421> "\213D$\f\205\300u#H\213D$\020H\213L$\030dH3\f%(", len = 870530016}, {s = 0x73ecfa7c <error: Cannot access memory at address 0x73ecfa7c>, len = 2015224608}, {s = 0xbb72a969dd690f00 <error: Cannot access memory at address 0xbb72a969dd690f00>, len = 870530016}}, u_val = {{s = 0x7f2c73ecf044 "\b", len = 0}, {s = 0x7f2c73e89489 ":9060; transport=udp; version=3", len = 1}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = -1520612208}, {s = 0x7f2c73ecfa80 "1a17c797-b66e-4fc7-9bcd-1d377685d0fd", len = 1944911760}, {s = 0x10 <error: Cannot access memory at address 0x10>, len = 2}, {s = 0x7f2c73ecf048 "(\374\354s,\177", len = 1944912008}, {s = 0x10 <error: Cannot access memory at address 0x10>, len = 2}, {s = 0x7f2c781de320 <resbuf> "\b", <incomplete sequence \305>, len = 2}, {s = 0x7f2c2a7d75f8 <hep_udp_send+99> "A\211ƃ\370\377\017\205@\001", len = 3}, {s = 0x35d <error: Cannot access memory at address 0x35d>, len = 0}}, u_params_no = 0}
        next_hop = {user = {s = 0x35d <error: Cannot access memory at address 0x35d>, len = 1260}, passwd = {s = 0x1000000010 <error: Cannot access memory at address 0x1000000010>, len = -1520615064}, host = {s = 0x4ec <error: Cannot access memory at address 0x4ec>, len = 1944907824}, port = {s = 0x4ec <error: Cannot access memory at address 0x4ec>, len = 4458897}, params = {s = 0x7f2c73ecbb08 "\"", len = 1944894368}, headers = {s = 0x7f2c73ece148 "\246\b", len = -1520614928}, port_no = 48184, proto = 29676, type = 32556, transport = {s = 0x7f2c73f17b38 " \274\354s,\177", len = 5}, ttl = {s = 0x4ec2e9 <pv_set_scriptvar+67> "H\205\300\017\204\016\001", len = -1520614720}, user_param = {s = 0x7a <error: Cannot access memory at address 0x7a>, len = 5}, maddr = {s = 0x7f2c73f12c70 "\002", len = 1944904008}, method = {s = 0x7f2c73f17b38 " \274\354s,\177", len = 5}, lr = {s = 0x4fb5a2 <pv_set_value+199> "H\203\304\070[]\303H\213o\020H\205\355t\347H\211L$\030\211T$\024H\211t$\bH\211\337\377\325H\211\303H\215@\377H\203\370\375w\024H\213t$\bH\213F\020\213T$\024H\213L$\030\353\263H\213\025\233\253@", len = 9816444}, r2 = {s = 0x5 <error: Cannot access memory at address 0x5>, len = 51563}, gr = {s = 0x7f2c3418c608 "Ԓj.,\177", len = 1944904008}, transport_val = {s = 0x7f2c73f17b38 " \274\354s,\177", len = 719652896}, ttl_val = {s = 0x7f2c73ece148 "\246\b", len = 1945205560}, user_param_val = {s = 0x7f2c2ac3d3ec <get_source_group+1253> "\205\300\017\210", <incomplete sequence \326>, len = 1944904008}, maddr_val = {s = 0x7f2c73ece318 "\002", len = 780865720}, method_val = {s = 0x7f2c345f8e40 "\220\233\357\064,\177", len = 780865712}, lr_val = {s = 0x7f2c73e93470 "\020", len = 2}, r2_val = {s = 0x7f2c73ece148 "\246\b", len = 1944663376}, gr_val = {s = 0x7f2c73ece148 "\246\b", len = 0}, u_name = {{s = 0x437b76 <run_action_list+71> "\211Ņ\300u\a\203\r\225.M", len = 1944904136}, {s = 0x7f2c73e926c8 "\a", len = 2}, {s = 0x0, len = 2}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 1944663376}, {s = 0x7f2c73ece148 "\246\b", len = 0}, {s = 0x47fa56 <eval_elem+884> "\351\301\375\377\377A\274\373\377\377\377L\213- gH", len = 7}, {s = 0x0, len = 2}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 1944659880}, {s = 0x7f2c73ece148 "\246\b", len = 0}, {s = 0x47fa56 <eval_elem+884> "\351\301\375\377\377A\274\373\377\377\377L\213- gH", len = 1944647000}}, u_val = {{s = 0x10 <error: Cannot access memory at address 0x10>, len = 780864096}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 0}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 53}, {s = 0x7 <error: Cannot access memory at address 0x7>, len = 0}, {s = 0x4fda70 <pv_set_avp+659> "\205\300xF1\300\351\300\376\377\377H\205\311f\220\017\204\270\001", len = 712845347}, {s = 0x7ffca55d4450 "\a", len = 7}, {s = 0x7f2c358afab0 "", len = 712846752}, {s = 0x3 <error: Cannot access memory at address 0x3>, len = 1944663376}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 1944904008}, {s = 0x0, len = 0}}, u_params_no = 62895}
        u = <optimized out>
        port = 0
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        model = <optimized out>
        val = {rs = {s = 0x100000000 <error: Cannot access memory at address 0x100000000>, len = 0}, ri = 2147483647, flags = 0}
        pve = <optimized out>
        name_s = {s = 0x100000000000400 <error: Cannot access memory at address 0x100000000000400>, len = 0}
        start = {tv_sec = 12924240, tv_usec = 139828967080706}
        aux_counter = 0
        __FUNCTION__ = "do_action"
#21 0x0000000000437b76 in run_action_list (a=<optimized out>, msg=0x7f2c73ece148) at action.c:172
        ret = -1
        t = 0x7f2c73e7f428
#22 0x0000000000437eb7 in run_actions (a=<optimized out>, msg=<optimized out>) at action.c:137
        ret = <optimized out>
        msg = <optimized out>
        a = <optimized out>
        ret = <optimized out>
#23 0x0000000000433c21 in do_action (a=a@entry=0x7f2c73e979e0, msg=msg@entry=0x7f2c73ece148) at action.c:761
        increment = <optimized out>
        decrement = <optimized out>
        j = <optimized out>
        num_rows = 9816536
        val_s = {s = 0x1 <error: Cannot access memory at address 0x1>, len = -1520613144}
        cdb_reply = 0x40
        num_cols = <optimized out>
        aux = {s = 0x1 <error: Cannot access memory at address 0x1>, len = -1520613144}
        i = <optimized out>
        it = <optimized out>
        avp_val = <optimized out>
        avp_name = {n = 1, s = {s = 0x1 <error: Cannot access memory at address 0x1>, len = -1520613144}}
        avp_type = 4
        ret = -5
        v = <optimized out>
        sec = <optimized out>
        usec = <optimized out>
        to = <optimized out>
        p = <optimized out>
        tmp = <optimized out>
        new_uri = <optimized out>
        end = <optimized out>
        crt = <optimized out>
        len = <optimized out>
        i = <optimized out>
        user = 0
        expires = 0
        vals = {{s = 0x40 <error: Cannot access memory at address 0x40>, len = -1520613776}, {s = 0xffffffffffffffb0 <error: Cannot access memory at address 0xffffffffffffffb0>, len = 0}, {s = 0x3000000002 <error: Cannot access memory at address 0x3000000002>, len = 0}, {s = 0x0, len = 91}, {s = 0x20000007c <error: Cannot access memory at address 0x20000007c>, len = -1520612119}}
        result = {s = 0x7ffca55d49a0 "h\356\350s,\177", len = 105}
        uri = {user = {s = 0xc536d0 "D", <incomplete sequence \305>, len = -1520612119}, passwd = {s = 0x2 <error: Cannot access memory at address 0x2>, len = -1520613632}, host = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 691755205}, port = {s = 0x2 <error: Cannot access memory at address 0x2>, len = 12924744}, params = {s = 0x7ffca55d4c90 "\220\260\201\200", len = -1520613632}, headers = {s = 0x4 <error: Cannot access memory at address 0x4>, len = 2015246784}, port_no = 492, proto = 0, type = ERROR_URI_T, transport = {s = 0x1a55d4720 <error: Cannot access memory at address 0x1a55d4720>, len = 2015224608}, ttl = {s = 0x7f2c788126c0 "", len = -1520609700}, user_param = {s = 0x0, len = 9550720}, maddr = {s = 0x4 <error: Cannot access memory at address 0x4>, len = -1520613376}, method = {s = 0x1000100000001e8 <error: Cannot access memory at address 0x1000100000001e8>, len = 12997936}, lr = {s = 0x0, len = 12924208}, r2 = {s = 0xc53530 "", len = 12924632}, gr = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 12924640}, transport_val = {s = 0xc536c0 "4", <incomplete sequence \305>, len = 12924632}, ttl_val = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 12924640}, user_param_val = {s = 0xc536c0 "4", <incomplete sequence \305>, len = 0}, maddr_val = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 0}, method_val = {s = 0x2781debe0 <error: Cannot access memory at address 0x2781debe0>, len = 0}, lr_val = {s = 0x100000001 <error: Cannot access memory at address 0x100000001>, len = -1520613144}, r2_val = {s = 0x7ffca55d4714 "s-east-1\ainintca\003com", len = 1986228241}, gr_val = {s = 0x6e2d7065682d7265 <error: Cannot access memory at address 0x6e2d7065682d7265>, len = 1963549292}, u_name = {{s = 0x696e6907312d7473 <error: Cannot access memory at address 0x696e6907312d7473>, len = 1633907822}, {s = 0x6e2d7065682d7200 <error: Cannot access memory at address 0x6e2d7065682d7200>, len = 1963549292}, {s = 0x696e6907312d7473 <error: Cannot access memory at address 0x696e6907312d7473>, len = 1633907822}, {s = 0xbb72a969dd690f00 <error: Cannot access memory at address 0xbb72a969dd690f00>, len = 9731880}, {s = 0x3 <error: Cannot access memory at address 0x3>, len = 12997936}, {s = 0x7f2c781debe0 <_res@GLIBC_2.2.5> "\002", len = 0}, {s = 0x0, len = -1520611096}, {s = 0x7f2c781e6d3f <__res_context_search+735> "\211D$hH\203\304\060\205\300\177%\366D$$\001u\036\205\300uJM\205\366tEE\213\036E\205\333~=\307D$8", len = 1024}, {s = 0x7ffca55d50e8 "\233\003O", len = 0}, {s = 0x0, len = 0}}, u_val = {{s = 0x0, len = 0}, {s = 0x91bb80 <tmp> "pcv-homer-hep-nlb.us-east-1.inintca.com", len = 0}, {s = 0x0, len = 1024}, {s = 0x100000001 <error: Cannot access memory at address 0x100000001>, len = -1520612208}, {s = 0x69 <error: Cannot access memory at address 0x69>, len = 1024}, {s = 0x100000001 <error: Cannot access memory at address 0x100000001>, len = -1520612176}, {s = 0xbb72a96900000069 <error: Cannot access memory at address 0xbb72a96900000069>, len = 1944314768}, {s = 0xc4c910 "@", <incomplete sequence \305>, len = 0}, {s = 0x7f2c73ea2e98 "\020\311", <incomplete sequence \304>, len = 9731880}, {s = 0x0, len = -1520613144}}, u_params_no = 22378}
        next_hop = {user = {s = 0x1 <error: Cannot access memory at address 0x1>, len = -1520613144}, passwd = {s = 0x0, len = 2012239604}, host = {s = 0x2 <error: Cannot access memory at address 0x2>, len = 3}, port = {s = 0x9481b7 <tcp_current_req+663> "\r\nUser-Agent: ININ-EDGE/1.0.0.8450\r\nContent-Length: 0\r\n\r\n", len = 5717618}, params = {s = 0x7f2c73ea2e98 "\020\311", <incomplete sequence \304>, len = 9731880}, headers = {s = 0x3 <error: Cannot access memory at address 0x3>, len = 5546755}, port_no = 57672, proto = 29676, type = 32556, transport = {s = 0x9481b2 <tcp_current_req+658> "1 BYE\r\nUser-Agent: ININ-EDGE/1.0.0.8450\r\nContent-Length: 0\r\n\r\n", len = 9732592}, ttl = {s = 0x9481b2 <tcp_current_req+658> "1 BYE\r\nUser-Agent: ININ-EDGE/1.0.0.8450\r\nContent-Length: 0\r\n\r\n", len = 9732592}, user_param = {s = 0x7f2c73ecf780 "\003", len = 0}, maddr = {s = 0x550916 <get_hdr_field+710> "H\211\303H\205\300\017\204O\t", len = 16}, method = {s = 0x7f2c2eb42240 <cmds+480> " u\223.,\177", len = 0}, lr = {s = 0x7ffca55d4a10 "", len = 16}, r2 = {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = -1520610752}, gr = {s = 0x7ffca55d4a30 "", len = 16}, transport_val = {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 1944649704}, ttl_val = {s = 0x7f2c73e8fdd0 "\020", len = 2}, user_param_val = {s = 0x7f2c73ece148 "\246\b", len = 1944649704}, maddr_val = {s = 0x7f2c73ece148 "\246\b", len = -1520612784}, method_val = {s = 0x7f2c73e90068 "\002", len = 1944904008}, lr_val = {s = 0x4fb76c <pv_get_spec_value+253> "\205\300\017\205h\377\377\377H\213s`H\205\366\017\204[\377\377\377L\211\342H\211\357\350\245\305\374\377\351K\377\377\377L\213h\020M\205\355t\305H\213\025\347\251@", len = 1944645224}, r2_val = {s = 0x0, len = 0}, gr_val = {s = 0x14 <error: Cannot access memory at address 0x14>, len = 2}, u_name = {{s = 0x7f2c73e90068 "\002", len = 1944904008}, {s = 0x47f879 <eval_elem+407> "\205\300\017\204\262\004", len = 2}, {s = 0x7f2c73ece148 "\246\b", len = 1944647224}, {s = 0x7f2c73ece148 "\246\b", len = 0}, {s = 0x437b76 <run_action_list+71> "\211Ņ\300u\a\203\r\225.M", len = 0}, {s = 0x4fb76c <pv_get_spec_value+253> "\205\300\017\205h\377\377\377H\213s`H\205\366\017\204[\377\377\377L\211\342H\211\357\350\245\305\374\377\351K\377\377\377L\213h\020M\205\355t\305H\213\025\347\251@", len = 9816470}, {s = 0x1 <error: Cannot access memory at address 0x1>, len = 0}, {s = 0x0, len = 1944647224}, {s = 0x7f2c73ece148 "\246\b", len = 9816470}, {s = 0x1 <error: Cannot access memory at address 0x1>, len = 5}}, u_val = {{s = 0x7f2c2f7e04c0 <cmds+384> "w\311]/,\177", len = 16}, {s = 0x7f2c73ece148 "\246\b", len = 1944904008}, {s = 0x430427 <do_action+8424> "A\211\307D\017\266#\351\307\337\377\377A\203\377\003\017\204<+", len = 0}, {s = 0x4 <error: Cannot access memory at address 0x4>, len = 1944649832}, {s = 0x2 <error: Cannot access memory at address 0x2>, len = 1944904008}, {s = 0x0, len = 0}, {s = 0x47f5af <eval_expr+404> "\213\035\033\271H", len = 9816536}, {s = 0x1 <error: Cannot access memory at address 0x1>, len = 3}, {s = 0x7f2c73e900b8 "\001", len = 4}, {s = 0x7f2c73ece148 "\246\b", len = 0}}, u_params_no = 62939}
        u = <optimized out>
        port = 0
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        model = <optimized out>
        val = {rs = {s = 0x95c9d8 <int2str_buf+152> "2", len = 1}, ri = 5, flags = 28}
        pve = <optimized out>
        name_s = {s = 0x0, len = 9550720}
        start = {tv_sec = 9816404, tv_usec = 1}
        aux_counter = 1
        __FUNCTION__ = "do_action"
#24 0x0000000000437b76 in run_action_list (a=<optimized out>, msg=0x7f2c73ece148) at action.c:172
        ret = -1
        t = 0x7f2c73e979e0
#25 0x0000000000437eb7 in run_actions (a=<optimized out>, msg=<optimized out>) at action.c:137
        ret = <optimized out>
        msg = <optimized out>
        a = <optimized out>
        ret = <optimized out>
#26 0x0000000000433c21 in do_action (a=a@entry=0x7f2c73e90578, msg=msg@entry=0x7f2c73ece148) at action.c:761
        increment = <optimized out>
        decrement = <optimized out>
        j = <optimized out>
        num_rows = 0
        val_s = {s = 0x1d <error: Cannot access memory at address 0x1d>, len = 0}
        cdb_reply = 0x30001008081b090
        num_cols = <optimized out>
        aux = {s = 0x1d <error: Cannot access memory at address 0x1d>, len = 0}
        i = <optimized out>
        it = <optimized out>
        avp_val = <optimized out>
        avp_name = {n = 29, s = {s = 0x1d <error: Cannot access memory at address 0x1d>, len = 0}}
        avp_type = 9920
        ret = -5
        v = <optimized out>
        sec = <optimized out>
        usec = <optimized out>
        to = <optimized out>
        p = <optimized out>
        tmp = <optimized out>
        new_uri = <optimized out>
        end = <optimized out>
        crt = <optimized out>
        len = <optimized out>
        i = <optimized out>
        user = 0
        expires = 0
        vals = {{s = 0x30001008081b090 <error: Cannot access memory at address 0x30001008081b090>, len = 0}, {s = 0x682d72656d6f682d <error: Cannot access memory at address 0x682d72656d6f682d>, len = 1848471653}, {s = 0x312d747361652d73 <error: Cannot access memory at address 0x312d747361652d73>, len = 1768843527}, {s = 0x100006d6f6303 <error: Cannot access memory at address 0x100006d6f6303>, len = 835585}, {s = 0xc6200a0400330000 <error: Cannot access memory at address 0xc6200a0400330000>, len = 835724}}
        result = {s = 0x7f2c781de320 <resbuf> "\b", <incomplete sequence \305>, len = 2}
        uri = {user = {s = 0xf4200a0400330000 <error: Cannot access memory at address 0xf4200a0400330000>, len = 835615}, passwd = {s = 0xa3200a0400330000 <error: Cannot access memory at address 0xa3200a0400330000>, len = 835795}, host = {s = 0xc6200a0400330000 <error: Cannot access memory at address 0xc6200a0400330000>, len = 835724}, port = {s = 0xf4200a0400330000 <error: Cannot access memory at address 0xf4200a0400330000>, len = 31}, params = {s = 0x0, len = 0}, headers = {s = 0x0, len = 0}, port_no = 0, proto = 0, type = ERROR_URI_T, transport = {s = 0x0, len = 0}, ttl = {s = 0x0, len = 0}, user_param = {s = 0x0, len = 0}, maddr = {s = 0x0, len = 2015210560}, method = {s = 0xffffffffffffffb0 <error: Cannot access memory at address 0xffffffffffffffb0>, len = 10}, lr = {s = 0x3df <error: Cannot access memory at address 0x3df>, len = 4112}, r2 = {s = 0x7f2c293b5f0e <gethostbyname3_context+174> "H\205\300\017\204\241\002", len = -1520611848}, gr = {s = 0x0, len = 0}, transport_val = {s = 0x400 <error: Cannot access memory at address 0x400>, len = 12924208}, ttl_val = {s = 0x7f2c788126c0 "", len = 0}, user_param_val = {s = 0xc61760 "\300\254\035x,\177", len = -1520611784}, maddr_val = {s = 0x7ffca55d49a0 "h\356\350s,\177", len = 0}, method_val = {s = 0x400 <error: Cannot access memory at address 0x400>, len = 12924208}, lr_val = {s = 0x7f2c788126c0 "", len = 0}, r2_val = {s = 0xc800f0 "0\231", <incomplete sequence \307>, len = 0}, gr_val = {s = 0x7ffca55d49e0 "\002", len = -80}, u_name = {{s = 0xa <error: Cannot access memory at address 0xa>, len = 991}, {s = 0x0, len = 12662304}, {s = 0x7f2c77eabf89 <malloc+137> "H\205\300H\211\302\017\204", <incomplete sequence \373>, len = 783561088}, {s = 0x51c364 <del_lump+162> "H\211\303H\205\300\017\204|\001", len = -1}, {s = 0x1000 <error: Cannot access memory at address 0x1000>, len = 4096}, {s = 0x7f2c77e9682a <__GI__IO_file_doallocate+170> "\270\001", len = 64771}, {s = 0xac <error: Cannot access memory at address 0xac>, len = 2015210560}, {s = 0xffffffffffffffb0 <error: Cannot access memory at address 0xffffffffffffffb0>, len = 10}, {s = 0x3df <error: Cannot access memory at address 0x3df>, len = 4112}, {s = 0x7f2c77eaa62d <_int_malloc+1725> "D\213T$\030\351\204\373\377\377f\017\037\204", len = 8}}, u_val = {{s = 0x1000 <error: Cannot access memory at address 0x1000>, len = 2015210560}, {s = 0x7 <error: Cannot access memory at address 0x7>, len = 0}, {s = 0xbd6808 "ponse", len = 4144}, {s = 0x7f2c77eaa62d <_int_malloc+1725> "D\213T$\030\351\204\373\377\377f\017\037\204", len = -80}, {s = 0x40 <error: Cannot access memory at address 0x40>, len = 257}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 1}, {s = 0x6f00000063 <error: Cannot access memory at address 0x6f00000063>, len = 124}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = -80}, {s = 0x947fe1 <tcp_current_req+193> ";tag=MYsCGs8\r\nCall-ID: 2229dad0-7d67-44cb-925c-48819ec7ae52\r\nMax-Forwards: 69\r\nVia: SIP/2.0/TCP 10.32.29.233:60867;branch=z9hG4bK3106333350SU5JTi9pM3NpcC4t_89242061_\r\nRoute: <sip:52.206.40.246:5060;tr"..., len = 29}, {s = 0x0, len = 1944914408}}, u_params_no = 18188}
        next_hop = {user = {s = 0x1d <error: Cannot access memory at address 0x1d>, len = 0}, passwd = {s = 0x7f2c73ed09e8 "\001", len = 710559512}, host = {s = 0x7f2c2a5a470c <tls_current_req+204> ";tag=139713\r\ncall-id: 1a17c797-b66e-4fc7-9bcd-1d377685d0fd\r\nCSeq: 1 INVITE\r\nallow-events: conference, talk, hold\r\nContact:  <sip:+903083460804@10.30.181.43:5061;transport=tls>\r\nx-phonesim-proxy-type: "..., len = 5724012}, port = {s = 0x1000 <error: Cannot access memory at address 0x1000>, len = 2011785258}, params = {s = 0x7ffca55d5074 "\035", len = 29}, headers = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 33188}, port_no = 0, proto = 0, type = ERROR_URI_T, transport = {s = 0x947fe1 <tcp_current_req+193> ";tag=MYsCGs8\r\nCall-ID: 2229dad0-7d67-44cb-925c-48819ec7ae52\r\nMax-Forwards: 69\r\nVia: SIP/2.0/TCP 10.32.29.233:60867;branch=z9hG4bK3106333350SU5JTi9pM3NpcC4t_89242061_\r\nRoute: <sip:52.206.40.246:5060;tr"..., len = 1944914408}, ttl = {s = 0xa <error: Cannot access memory at address 0xa>, len = 9732017}, user_param = {s = 0x7f2c2a5a470c <tls_current_req+204> ";tag=139713\r\ncall-id: 1a17c797-b66e-4fc7-9bcd-1d377685d0fd\r\nCSeq: 1 INVITE\r\nallow-events: conference, talk, hold\r\nContact:  <sip:+903083460804@10.30.181.43:5061;transport=tls>\r\nx-phonesim-proxy-type: "..., len = 1944914408}, maddr = {s = 0xa <error: Cannot access memory at address 0xa>, len = 710559445}, method = {s = 0x0, len = 710559500}, lr = {s = 0x57b45e <parse_to+2508> "H\211ËM0D\213d$$\351\023\372\377\377L\211\373@\204\377\017\205\037\023", len = 0}, r2 = {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 0}, gr = {s = 0x7f2c73ece148 "\246\b", len = 60}, transport_val = {s = 0x7f2c73ece148 "\246\b", len = 0}, ttl_val = {s = 0x7f2c73ece148 "\246\b", len = 66}, user_param_val = {s = 0x7f2c73ed09e8 "\001", len = 1944420288}, maddr_val = {s = 0x7f2c73ece148 "\246\b", len = 1944904008}, method_val = {s = 0x5416ff <parse_from_header+184> "A\213,$\203\375\377\017\204\201\001", len = -1520610896}, lr_val = {s = 0x7f2c73ece148 "\246\b", len = 1944904008}, r2_val = {s = 0x7f2c73ece148 "\246\b", len = -1520610864}, gr_val = {s = 0x4f039b <pv_get_to_attr+66> "H\203\304\020[]A\\\303\061Ҿ\b", len = -1520610896}, u_name = {{s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 1944421024}, {s = 0x7f2c73ece148 "\246\b", len = -1520610864}, {s = 0x4fb76c <pv_get_spec_value+253> "\205\300\017\205h\377\377\377H\213s`H\205\366\017\204[\377\377\377L\211\342H\211\357\350\245\305\374\377\351K\377\377\377L\213h\020M\205\355t\305H\213\025\347\251@", len = 1944417504}, {s = 0x7ffca55d52b0 "\a", len = 30}, {s = 0x0, len = 52}, {s = 0x7f2c73ece148 "\246\b", len = 1944904008}, {s = 0x47fce2 <eval_elem+1536> "H\205\300\017\204W\f", len = 2}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 1944417504}, {s = 0x7f2c73ece148 "\246\b", len = 1944904008}, {s = 0x47fa56 <eval_elem+884> "\351\301\375\377\377A\274\373\377\377\377L\213- gH", len = 1944904008}}, u_val = {{s = 0x7f2c73e57ad8 " {\345s,\177", len = -1520610800}, {s = 0x7f2c73e57af0 "\230\352\354s,\177", len = 1944904008}, {s = 0x7f2c73ece148 "\246\b", len = 1944904008}, {s = 0x4e70f7 <set_var_value+1032> "H\211C\030H\205\300u\263L\213\025\201\360A", len = 710559384}, {s = 0x33 <error: Cannot access memory at address 0x33>, len = 1944420768}, {s = 0x7f2c73e58188 "N", len = -1520610640}, {s = 0x4ec3f7 <pv_set_scriptvar+337> "H\205\300\017\205\362\376\377\377H\213\065\201\235A", len = 1944904008}, {s = 0x7f2c73e58188 "N", len = 1944916688}, {s = 0x33 <error: Cannot access memory at address 0x33>, len = 1944904008}, {s = 0x7f2c73e58188 "N", len = -1520610640}}, u_params_no = 46498}
        u = <optimized out>
        port = 145
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        model = <optimized out>
        val = {rs = {s = 0x0, len = 0}, ri = 0, flags = 0}
        pve = <optimized out>
        name_s = {s = 0x7ffca55d565c "\374\177", len = 691757217}
        start = {tv_sec = 12924208, tv_usec = 1024}
        aux_counter = 0
        __FUNCTION__ = "do_action"
#27 0x0000000000437b76 in run_action_list (a=<optimized out>, msg=0x7f2c73ece148) at action.c:172
        ret = -1
        t = 0x7f2c73e90578
#28 0x0000000000437eb7 in run_actions (a=<optimized out>, msg=<optimized out>) at action.c:137
        ret = <optimized out>
        msg = <optimized out>
        a = <optimized out>
        ret = <optimized out>
#29 0x0000000000433c21 in do_action (a=a@entry=0x7f2c73e584e8, msg=msg@entry=0x7f2c73ece148) at action.c:761
        increment = <optimized out>
        decrement = <optimized out>
        j = <optimized out>
        num_rows = -1569769595
        val_s = {s = 0x7ffca55d5830 "\237JZ*,\177", len = 887829072}
        cdb_reply = 0x5a8279995a827999
        num_cols = <optimized out>
        aux = {s = 0x7ffca55d5830 "\237JZ*,\177", len = 887829072}
        i = <optimized out>
        it = <optimized out>
        avp_val = <optimized out>
        avp_name = {n = -1520609232, s = {s = 0x7ffca55d5830 "\237JZ*,\177", len = 887829072}}
        avp_type = 52752
        ret = -5
        v = <optimized out>
        sec = <optimized out>
        usec = <optimized out>
        to = <optimized out>
        p = <optimized out>
        tmp = <optimized out>
        new_uri = <optimized out>
        end = <optimized out>
        crt = <optimized out>
        len = <optimized out>
        i = <optimized out>
        user = 0
        expires = 0
        vals = {{s = 0x5a8279995a827999 <error: Cannot access memory at address 0x5a8279995a827999>, len = 1518500249}, {s = 0x5a8279995a827999 <error: Cannot access memory at address 0x5a8279995a827999>, len = 1518500249}, {s = 0x5a8279995a827999 <error: Cannot access memory at address 0x5a8279995a827999>, len = 701049934}, {s = 0x5a8279995a827999 <error: Cannot access memory at address 0x5a8279995a827999>, len = 1518500249}, {s = 0x7f2c3531d238 "\363\300\224+\222([\232\302\016-\203:P0wINVITE sip:12287281077@testacdload77.byoc.inintca.com:5061;transport=TLS SIP/2.0\r\nTo:  <sip:12287281077@testacdload77.byoc.inintca.com:5061>\r\nFrom:  <sip:+903083460804@testacdload77.by"..., len = 701973548}}
        result = {s = 0xc89c20 "", len = 2015196160}
        uri = {user = {s = 0xf9cbdba891a92102 <error: Cannot access memory at address 0xf9cbdba891a92102>, len = 705811726}, passwd = {s = 0x7f2c353020d0 "", len = 1}, host = {s = 0x7f2c353016d0 "", len = 1}, port = {s = 0x0, len = 705813811}, params = {s = 0x7f2c34b16888 "\300\002\r*,\177", len = 1}, headers = {s = 0x7ffca55d56bd "\177", len = 892343936}, port_no = 16, proto = 0, type = ERROR_URI_T, transport = {s = 0xe49bc6318d295000 <error: Cannot access memory at address 0xe49bc6318d295000>, len = -1520609872}, ttl = {s = 0x7f2c2a0d02c0 <aesni_256_cbc> "\253\001", len = 0}, user_param = {s = 0x7f2c353020d0 "", len = 892346584}, maddr = {s = 0x7ffca55d54b0 "p\004", len = 1136}, method = {s = 0x3b21e5ef26a38154 <error: Cannot access memory at address 0x3b21e5ef26a38154>, len = 1604711116}, lr = {s = 0x861792618dc1f708 <error: Cannot access memory at address 0x861792618dc1f708>, len = 1604711116}, r2 = {s = 0x861792618dc1f708 <error: Cannot access memory at address 0x861792618dc1f708>, len = -1369254747}, gr = {s = 0x7dab237218743f17 <error: Cannot access memory at address 0x7dab237218743f17>, len = -1369254747}, transport_val = {s = 0x7dab237218743f17 <error: Cannot access memory at address 0x7dab237218743f17>, len = 461691903}, ttl_val = {s = 0xdc27d5314671415e <error: Cannot access memory at address 0xdc27d5314671415e>, len = 461691903}, user_param_val = {s = 0xdc27d5314671415e <error: Cannot access memory at address 0xdc27d5314671415e>, len = -1377536311}, maddr_val = {s = 0x22030643d54a3137 <error: Cannot access memory at address 0x22030643d54a3137>, len = -1377536311}, method_val = {s = 0x22030643d54a3137 <error: Cannot access memory at address 0x22030643d54a3137>, len = -2103250763}, lr_val = {s = 0xe9960ac017c37cdd <error: Cannot access memory at address 0xe9960ac017c37cdd>, len = -2103250763}, r2_val = {s = 0xe9960ac017c37cdd <error: Cannot access memory at address 0xe9960ac017c37cdd>, len = -528578154}, gr_val = {s = 0xa6d42103fd2e0b24 <error: Cannot access memory at address 0xa6d42103fd2e0b24>, len = -528578154}, u_name = {{s = 0xa6d42103fd2e0b24 <error: Cannot access memory at address 0xa6d42103fd2e0b24>, len = -1118089502}, {s = 0x46736533c4fa065d <error: Cannot access memory at address 0x46736533c4fa065d>, len = -1118089502}, {s = 0x46736533c4fa065d <error: Cannot access memory at address 0x46736533c4fa065d>, len = 1191457719}, {s = 0x2e3e127fc1481cf9 <error: Cannot access memory at address 0x2e3e127fc1481cf9>, len = 1191457719}, {s = 0x2e3e127fc1481cf9 <error: Cannot access memory at address 0x2e3e127fc1481cf9>, len = -438823051}, {s = 0xe4136d87da42e9b4 <error: Cannot access memory at address 0xe4136d87da42e9b4>, len = -438823051}, {s = 0xe4136d87da42e9b4 <error: Cannot access memory at address 0xe4136d87da42e9b4>, len = -1717235205}, {s = 0xcaee9c25292f2b76 <error: Cannot access memory at address 0xcaee9c25292f2b76>, len = -1717235205}, {s = 0xcaee9c25292f2b76 <error: Cannot access memory at address 0xcaee9c25292f2b76>, len = 889240306}, {s = 0x87f895e80e831f3a <error: Cannot access memory at address 0x87f895e80e831f3a>, len = -1538352159}}, u_val = {{s = 0xfd181f03d49b255a <error: Cannot access memory at address 0xfd181f03d49b255a>, len = -999603242}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 1421704995}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 1639635562}, {s = 0x55857925f60a1926 <error: Cannot access memory at address 0x55857925f60a1926>, len = -1520609232}, {s = 0x7ffca55d56d0 "\260ʕ", len = 878474180}, {s = 0x7ffca55d58e0 "\237JZ*,\177", len = 878474152}, {s = 0x7f2c29de9c5b <SHA1_Final+171> "\213\003H\211\301H\211\302H\301\351\030\210U\003\210M", len = 887829072}, {s = 0x7ffca55d574c ",\177", len = -1520609460}, {s = 0x7f2c29d73aa2 <EVP_DigestFinal_ex+82> "D\211\340[]A\\\303H\215\065\336\a\017", len = 889710288}, {s = 0x7ffca55d58e0 "\237JZ*,\177", len = -1520609460}}, u_params_no = 6420}
        next_hop = {user = {s = 0x7ffca55d5830 "\237JZ*,\177", len = 887829072}, passwd = {s = 0x95cab0 <shm_block> "", len = 889710288}, host = {s = 0x95cab0 <shm_block> "", len = 881583616}, port = {s = 0x95cab0 <shm_block> "", len = 698325573}, params = {s = 0x7f2c348be600 "", len = 881200968}, headers = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 886412424}, port_no = 51888, proto = 149, type = ERROR_URI_T, transport = {s = 0x7f2c299f9a45 <os_free+93> "H\213\065\324\343 ", len = 886412424}, ttl = {s = 0x1 <error: Cannot access memory at address 0x1>, len = 9816752}, user_param = {s = 0x7f2c299f9a45 <os_free+93> "H\213\065\324\343 ", len = 1}, maddr = {s = 0x7f2c34d0b070 "\001", len = 1}, method = {s = 0x7f2c34338b90 "10.32.20.60", len = 9816752}, lr = {s = 0x7f2c348e6e18 "", len = 9816752}, r2 = {s = 0x7f2c358afab0 "", len = 9816752}, gr = {s = 0x7f2c299f9a45 <os_free+93> "H\213\065\324\343 ", len = 898300592}, transport_val = {s = 0x7f2c35b6ac00 "\240\071\r*,\177", len = 892343936}, ttl_val = {s = 0x7f2c34d0b070 "\001", len = 9816752}, user_param_val = {s = 0x7f2c299f9a45 <os_free+93> "H\213\065\324\343 ", len = 886091888}, maddr_val = {s = 0x0, len = 9816752}, method_val = {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 0}, lr_val = {s = 0x7f2c34d0b070 "\001", len = 892343936}, r2_val = {s = 0x7f2c353020d0 "", len = 0}, gr_val = {s = 0x7f2c2a5a4863 <tls_current_req+547> "061;branch=z9hG4bKb368ecc6e9544432bf841c18b1090a05\r\n\r\nv=0\r\no=- 2838320999 3776778278 IN IP4 10.30.210.43\r\ns= \r\nc=IN IP4 10.30.210.43\r\nt=0 0\r\nm=audio 31424 RTP/SAVP 96 0 97 101 102 103\r\na=rtpmap:96 opu"..., len = 6}, u_name = {{s = 0x7f2c2a5a4867 <tls_current_req+551> "branch=z9hG4bKb368ecc6e9544432bf841c18b1090a05\r\n\r\nv=0\r\no=- 2838320999 3776778278 IN IP4 10.30.210.43\r\ns= \r\nc=IN IP4 10.30.210.43\r\nt=0 0\r\nm=audio 31424 RTP/SAVP 96 0 97 101 102 103\r\na=rtpmap:96 opus/48"..., len = 710560415}, {s = 0x7f2c2a5a482d <tls_current_req+493> "SIP/2.0/TLS phonesim-container-phonesim-10-30-181-43:5061;branch=z9hG4bKb368ecc6e9544432bf841c18b1090a05\r\n\r\nv=0\r\no=- 2838320999 3776778278 IN IP4 10.30.210.43\r\ns= \r\nc=IN IP4 10.30.210.43\r\nt=0 0\r\nm=aud"..., len = -18}, {s = 0x55d47f <parse_via+14719> "I\211\304H\205\300D\213\\$DL\213L$HD\017\266T$P\017\204\254\254", len = 1944908528}, {s = 0x7f2c35300920 "\003\003", len = 892458664}, {s = 0x7f2c35301680 "\003\003", len = 20}, {s = 0x7f2c73ecf190 "\001", len = 1944908176}, {s = 0x7f2c2a5a4867 <tls_current_req+551> "branch=z9hG4bKb368ecc6e9544432bf841c18b1090a05\r\n\r\nv=0\r\no=- 2838320999 3776778278 IN IP4 10.30.210.43\r\ns= \r\nc=IN IP4 10.30.210.43\r\nt=0 0\r\nm=audio 31424 RTP/SAVP 96 0 97 101 102 103\r\na=rtpmap:96 opus/48"..., len = 1136}, {s = 0x7f2c2a5a4867 <tls_current_req+551> "branch=z9hG4bKb368ecc6e9544432bf841c18b1090a05\r\n\r\nv=0\r\no=- 2838320999 3776778278 IN IP4 10.30.210.43\r\ns= \r\nc=IN IP4 10.30.210.43\r\nt=0 0\r\nm=audio 31424 RTP/SAVP 96 0 97 101 102 103\r\na=rtpmap:96 opus/48"..., len = 710559488}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 876285008}, {s = 0x948035 <tcp_current_req+277> "SIP/2.0/TCP 10.32.29.233:60867;branch=z9hG4bK3106333350SU5JTi9pM3NpcC4t_89242061_\r\nRoute: <sip:52.206.40.246:5060;transport=tcp;ftag=388913;lr;r2=on>,\r\n\t<sip:10.32.20.60:5060;ftag=388913;lr;r2=on>\r\nAl"..., len = 6}}, u_val = {{s = 0x54a303 <parse_cseq+1251> "H\205\300uT\351}\001", len = 0}, {s = 0x7f2c2a5a482d <tls_current_req+493> "SIP/2.0/TLS phonesim-container-phonesim-10-30-181-43:5061;branch=z9hG4bKb368ecc6e9544432bf841c18b1090a05\r\n\r\nv=0\r\no=- 2838320999 3776778278 IN IP4 10.30.210.43\r\ns= \r\nc=IN IP4 10.30.210.43\r\nt=0 0\r\nm=aud"..., len = 710560415}, {s = 0x7f2c73ecf720 "\001", len = 0}, {s = 0x1 <error: Cannot access memory at address 0x1>, len = 1944908176}, {s = 0x550ca3 <get_hdr_field+1619> "H\211\303A\203?\377\017\204\245\a", len = 0}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = -1772959417}, {s = 0x1cc9f95f73a5bc0a <error: Cannot access memory at address 0x1cc9f95f73a5bc0a>, len = 0}, {s = 0x5203e1 <fm_malloc+846> "H\215C\030H\203\304([]A\\A]A^A_\303M\205\366\017\210\021\003", len = 0}, {s = 0x948030 <tcp_current_req+272> "Via: SIP/2.0/TCP 10.32.29.233:60867;branch=z9hG4bK3106333350SU5JTi9pM3NpcC4t_89242061_\r\nRoute: <sip:52.206.40.246:5060;transport=tcp;ftag=388913;lr;r2=on>,\r\n\t<sip:10.32.20.60:5060;ftag=388913;lr;r2=on"..., len = 2}, {s = 0x7f2c73e584e8 "\a", len = 897313680}}, u_params_no = 18472}
        u = <optimized out>
        port = 56681
        cmatch = <optimized out>
        aitem = <optimized out>
        adefault = <optimized out>
        spec = <optimized out>
        model = <optimized out>
        val = {rs = {s = 0xda827999a26f3785 <error: Cannot access memory at address 0xda827999a26f3785>, len = 1518500249}, ri = -1569769595, flags = -628983399}
        pve = <optimized out>
        name_s = {s = 0xa <error: Cannot access memory at address 0xa>, len = 2011844969}
        start = {tv_sec = 4579404359799459344, tv_usec = -8849325906990759588}
        aux_counter = -1150113431
        __FUNCTION__ = "do_action"
#30 0x0000000000437b76 in run_action_list (a=a@entry=0x7f2c73e57078, msg=msg@entry=0x7f2c73ece148) at action.c:172
        ret = -1
        t = 0x7f2c73e584e8
#31 0x000000000043802a in run_actions (msg=0x7f2c73ece148, a=0x7f2c73e57078) at action.c:137
        ret = <optimized out>
        msg = 0x7f2c73ece148
        a = 0x7f2c73e57078
        ret = <optimized out>
#32 run_top_route (a=0x7f2c73e57078, msg=msg@entry=0x7f2c73ece148) at action.c:214
        bk_action_flags = 0
        bk_rec_lev = 0
        ret = <optimized out>
        ctx = 0x0
        __FUNCTION__ = "run_top_route"
#33 0x000000000043ef2e in receive_msg (buf=0x7f2c2a5a4640 <tls_current_req> "INVITE sip:12287281077@testacdload77.byoc.inintca.com:5061;transport=TLS SIP/2.0\r\nTo:  <sip:12287281077@testacdload77.byoc.inintca.com:5061>\r\nFrom:  <sip:+903083460804@testacdload77.byoc.inintca.com:5"..., len=<optimized out>, len@entry=1119, rcv_info=rcv_info@entry=0x7ffca55d5b90, existing_context=existing_context@entry=0x0, flags=flags@entry=0) at receive.c:209
        ctx = 0x7f2c73ecf0e0
        msg = 0x7f2c73ece148
        start = {tv_sec = 139827847629088, tv_usec = 139827661172543}
        rc = 3
        in_buff = {s = 0x7f2c2a5a4640 <tls_current_req> "INVITE sip:12287281077@testacdload77.byoc.inintca.com:5061;transport=TLS SIP/2.0\r\nTo:  <sip:12287281077@testacdload77.byoc.inintca.com:5061>\r\nFrom:  <sip:+903083460804@testacdload77.byoc.inintca.com:5"..., len = 1119}
        __FUNCTION__ = "receive_msg"
#34 0x00007f2c2a39d11e in tcp_handle_req (_max_msg_chunks=<optimized out>, con=<optimized out>, req=0x7f2c2a5a4640 <tls_current_req>) at ../../net/proto_tcp/tcp_common.h:411
        local_rcv = {src_ip = {af = 2, len = 4, u = {addrl = {2048780306, 0}, addr32 = {2048780306, 0, 0, 0}, addr16 = {59410, 31261, 0, 0, 0, 0, 0, 0}, addr = "\022\350\035z", '\000' <repeats 11 times>}}, dst_ip = {af = 2, len = 4, u = {addrl = {1007951882, 0}, addr32 = {1007951882, 0, 0, 0}, addr16 = {8202, 15380, 0, 0, 0, 0, 0, 0}, addr = "\n \024<", '\000' <repeats 11 times>}}, src_port = 51563, dst_port = 5061, proto = 3, proto_reserved1 = 2017539748, proto_reserved2 = 0, src_su = {s = {sa_family = 2, sa_data = "\311k\022\350\035z\000\000\000\000\000\000\000"}, sin = {sin_family = 2, sin_port = 27593, sin_addr = {s_addr = 2048780306}, sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family = 2, sin6_port = 27593, 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}}, bind_address = 0x7f2c73e87c10}
        msg_buf = <optimized out>
        msg_len = <optimized out>
        c = 0 '\000'
        size = 0
#35 tls_read_req (con=0x7f2c34c35280, bytes_read=0x7ffca55d5ca0) at proto_tls.c:600
        bytes = <optimized out>
        total_bytes = 1119
        req = <optimized out>
        data = <optimized out>
        __FUNCTION__ = "tls_read_req"
#36 0x00000000005f5247 in handle_io (event_type=1, idx=68, fm=<optimized out>) at net/net_tcp_proc.c:241
        con = <optimized out>
        ret = 0
        n = <optimized out>
        rw = <optimized out>
        response = {9584996, 139638851103336}
        s = 0
        resp = <optimized out>
#37 io_wait_loop_epoll (h=<optimized out>, t=<optimized out>, repeat=<optimized out>) at net/../io_wait_loop.h:280
        ret = <optimized out>
        i = <optimized out>
        e = <optimized out>
        ep_event = {events = 0, data = {ptr = 0x0, fd = 0, u32 = 0, u64 = 0}}
        fd = <optimized out>
        n = 1
        r = 68
#38 tcp_worker_proc_loop () at net/net_tcp_proc.c:386
        __FUNCTION__ = "tcp_worker_proc_loop"
#39 0x0000000000603918 in tcp_start_processes (chd_rank=chd_rank@entry=0x924164 <chd_rank>, startup_done=startup_done@entry=0x7f2c341dea68) at net/net_tcp.c:1903
        r = 2
        reader_fd = {103, 105}
        pid = <optimized out>
        __FUNCTION__ = "tcp_start_processes"
#40 0x000000000041c1d1 in main_loop () at main.c:788
        startup_done = 0x7f2c341dea68
        rc = <optimized out>
        chd_rank = 19
#41 main (argc=<optimized out>, argv=<optimized out>) at main.c:1439
        cfg_stream = <optimized out>
        c = <optimized out>
        r = 0
        tmp = 0x7ffca55d7ecf ""
        tmp_len = <optimized out>
        port = <optimized out>
        proto = <optimized out>
        protos_no = <optimized out>
        options = 0x653a38 "f:cCm:M:b:l:n:N:rRvdDFEVhw:t:u:g:P:G:W:o:"
        ret = -1
        seed = 1283913054
        rfd = <optimized out>
        __FUNCTION__ = "main"

Please let me know if you have anything else that you want me to test. Currently TLS is just not stable for us to use on 2.4.6 and we would like to figure this issue out.

stale[bot] commented 4 years ago

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.

vitalikvoip commented 4 years ago

FYI it really looks like an openssl bug or some undocumented behavior. Took the latest libssl from their master branch and it still crashes. Tried kamailio with the similar pthread overwriting trick and latest debian 10 + libssl1.1 and it also crashed in the same libcrypto.so Installing libssl dbg symbols didn't really help with debugging. In the place it fails GDB shows an attempt to copy some data from an address saved in xmm registers while the address value is 0.

clifjones commented 4 years ago

FYI it really looks like an openssl bug or some undocumented behavior. Took the latest libssl from their master branch and it still crashes. Tried kamailio with the similar pthread overwriting trick and latest debian 10 + libssl1.1 and it also crashed in the same libcrypto.so Installing libssl dbg symbols didn't really help with debugging. In the place it fails GDB shows an attempt to copy some data from an address saved in xmm registers while the address value is 0.

OK, you mentioned Kamailio so I'm going to say what I have been thinking about but hesitant to post. First, my company is heavily invested in OpenSIPS, so I don't want to send the wrong message. I've noticed that Kamailio does not have as many issues on OpenSSL as OpenSIPS. Is that because they are not being publicly reported or have they found some tricks (like the one you mentioned) to get TLS stable? Since it was forked from the same parent project, I would think that it would be useful to take a peek at their code from time to time to see what new improvements can be made to the OpenSIPS code base since it is all open source code. If both projects are working with OpenSSL 1.0.2, then I guess both will be working to get over onto 1.1.1 since support now ends December 2019, unless they push out the EOL date again. I'm noticing that OpenSSL 1.0.2s seems to work in the success paths, but we usually see our problems with negative testing: bad certificates, wrong protocol on the TLS port, etc. We are working on standardizing our negative path testing and we can share more details once we can reliably point out the root cause of the failures.

razvancrainea commented 4 years ago

Apologies for getting back to this thread so late - although there was a bit of silence from myself, I did run some tests to understand what's the main cause of this crashes, and unfortunately it's the same cause as the one in ticket #1767, changes in the openssl version that are incompatible with multi-process applications. In this specific case, OpenSSL relies on the Threads-specific data mechanism to ensure it allocates memory private to each thread. However, it uses shm_memory to allocate this memory, resulting in accesses to memory that is no longer guarded by locks. Hence, after concurrent access to the same memory zone, both threads want to free some data, resulting in the double free/possible crash mentioned in this thread. I've currently written some code that prevents OpenSIPS from crashing, however, it is not behaving correctly - i.e. only 2 out of 20 connections are properly established. I will now run some more tests, I will keep you updated with my progress.

Best regards, Răzvan

clifjones commented 4 years ago

Thanks for the update. This explains the OpenSSL 1.1.1 issue and I believe that the crashes that we are relate to #1708. Amazon Linux 2 has FIPS enabled for OpenSSL 1.0.2k+.

razvancrainea commented 4 years ago

Actually the crashes are related to OpenSSL 1.1.1, but they are not there in 1.1.0 - in OpenSSL 1.1.0 only the "deadlock" issue in ticket #1767 is present, but this has already been solved.

bcnewlin commented 4 years ago

@razvancrainea The original reported crash by Dan was for openssl 1.1.1, but we had a separate ticket for crashes with OpenSIPS 2.4 and openssl 1.0.2 (#1771) that was closed against this one, with a request to consolidate the tickets into one. All of the info @clifjones has been providing about crashes has been for our configuration. If you'd like us to reopen a separate ticket for our crashes we can do so.

clifjones commented 4 years ago

I must say that combining the 1.1.x and 1.0.x OpenSSL issues is quite confusing.

danpascu commented 4 years ago

@razvancrainea Maybe you can share those changes and we can chime in with suggestions

razvancrainea commented 4 years ago

@danpascu you can apply this patch, but note that it is still WIP. My idea was to allocate for each process its own thread specific data, thus I overwrote the entire mechanism with my own functions. After applying it, I am trying to use your script to generate traffic, but only a few connections are accepted. Not sure if this is related to the way the python script works (I doubt), or there's still a problem with the code. I've also tried the ab tool to generate the traffic and seems to work just fine. Let me know if you have any other thoughts, as currently I am a bit stuck.

vitalikvoip commented 4 years ago

You might receive my post that confirms that the thread specific patch works fine. Already removed it. Accidentally used TCP instead of TLS.

danpascu commented 4 years ago

@razvancrainea If I write an echo server in python and use the test script with it, no connection fails, which leads me to conclude that there is still a problem in opensips if it only accepts a few connections.

Is the TLS context created in the main TCP process when a TLS connection is accepted and then passed to the processes that actually handle that connection?

There are still some things in the openssl code that do not seem correct. Unfortunately the documentation for them is between vague and non-existing, but the general consensus seems to be that if you call a function with some arguments and it returns one of the SSL_WANTS_READ|WRITE error codes, you need to wait for the socket to become readable/writable and then call the same function that failed with the same arguments. I do not see this being done as far as I understand the TLS code in opensips. Another thing that is not documented anywhere, but can result in weird behavior where one TLS context errors influence another TLS context is if the errors are not cleared after getting them.

danpascu commented 4 years ago

At this point, my suggestion is for a different approach. Rather than patching pthread functionality hoping to convince openssl to behave I'd consider a change in architecture.

My idea is to run a single main process that does networking using a reactor, like uvloop. This process is responsible only for sending/receiving data and is fully non-blocking which is a plus. Once it receives a full SIP message, it will pass it to a worker process, which now doesn't need to do any networking, it only needs to parse the message and call the appropriate route. When the worker process has a message to send out it will pass it back to the main networking process which will handle sending the message. By doing this we completely avoid all the threading issues in openssl as we only do networking in a single process.

After this I would also consider changing from a multi-process model to a multi-threaded model for the worker/timer processes which will get rid of the shared memory and allow on to use tools like ASAN/TSAN to find issues with memory access.

razvancrainea commented 4 years ago

@danpascu the way it works now, when OpenSIPS receives a new connection, the main TCP process only detects the event, accepts the connection (no SSL context is created yet), and puts the job handing in a queue. A free process takes that job from the queue, and creates the SSL context for it, and does the SSL_accept. After that, it starts reading data from that endpoint and process it.

I can confirm that OpenSIPS handles the SSL_WANTS_READ|WRITE return codes correct, so I doubt the problem is from here. But I do suspect the same you are, that some errorrs are not properly cleaned up, or they somehow get shared between different processes/threads, but I can't pinpoint what/how.

There are two issues with your suggestion:

  1. it can't be applied to older OpenSIPS releases (such as 2.4 and 3.0)
  2. it will have a huge impact in performance: in order to read a SIP message over TLS, we need to (partially) parse it to get the Content-Length of the message. If we do this in a single thread for all messages, it will be a big performance drop.

I agree that running with a library that is no longer suitable for is not OK, and if we do want to continue using it, we need a complete re-design of the architecture, but this needs to be done starting with OpenSIPS 3.1. For now my focus is sorting out older versions of OpenSIPS (that should be stable, such as 2.4 and 3.0) that can't have an architecture re-design right now, but still need to have this fixed. That's why I am focused on the approach of tuning bits and pieces of openssl/pthreads. So if my patch does not do too much harm, and it doesn't except it denies some (concurrent) connections, but it does fix some crashes, I would temporarily go with it. Until we figure out a better approach in OpenSIPS 3.1 at least.

danpascu commented 4 years ago

Yes, but my question is is that context that is created in that process then passed back to TCP Main and then later passed to another worker when some new messages are received over that connection? In other words is a TLS context created in some process end up being used in another process?

How many connections out of 100 does it accept? If it's less than 10, then you have a failure rate for concurrent connection greater than 90%, which is unworkable for anything past a test server.

My suggestion was not meant as a fix for the current code, but a way to move forward for the future releases. I also do not share your concern about performance, Parsing the content-length header is not that expensive, it can be done on the fly as you receive the message. Don't forget the context here: one process doing just network transfers plus the parsing of the content-length header is capable to provide the worker processes with more messages that they can handle. The bulk of processing time will be in the workers. Plus encryption itself is a few times more expensive than parsing a single header. Also my suggestion of using an asynchronous reactor loop was for all networking not just TLS.

danpascu commented 4 years ago

@razvancrainea The pastebin link has expired and I didn't download the patch. Can you please upload it again.

danpascu commented 4 years ago

Better yet attach the diff to this issue so it doesn't expire

razvancrainea commented 4 years ago

@danpascu in normal circumstances, the TLS(and any TCP) connection is kept in the process that created the SSL context. This connection is not passed back to TCP Main, unless it is idle for more than 5 seconds. This is not the case here, as the connection is not even accepted, so everything happens in a single process.

Regarding the failure rate, it's not too fortunate :(. 84 out of 100 fail:

$ ./tls_mgm_load.py -p 8888 -c 100 -m dummy
Connecting to localhost:8888 using 100 connections in dummy mode
time=1.26 sec; rate=79 requests/sec with localhost:8888
84 out of 100 connections have failed

Regarding parsing, previous profiling were indicating that SIP msg parsing takes more than 30% of the actual processing. Most likely this was done against full SIP parsing, not something we're doing for TLS, but it's worth mentioning.

danpascu commented 4 years ago

@razvancrainea Is there ANY circumstance under which a TLS context created in a process can end up being used by another process?

I have serious doubts that parsing takes more than 30% of all processing. Maybe if all you do is forward messages. As soon as you start doing real work, i.e. ENUM lookup, database access for various features, accessing external applications like media relay, call control, etc, plus the changes make to the message from the script, that is where parsing the message become insignificant. In addition, even if I take your figure of 30% as realistic, that is for parsing the whole message. You only need to parse the content-length header in the networking thread. Everything else will be parsed in the workers which removes the problem.

P.S. can you please reattach the patch here, pastebin is expired.

razvancrainea commented 4 years ago

@danpascu I agree with you, 30% is way too much, and indeed, only if you don't do a "real" processing of the traffic.

Here is the patch: ssl_crash_1.1.1.txt

danpascu commented 4 years ago

I tried a few things but nothing helped. I tried to increase the listen backlog, since it was only 10 and I thought it might have an influence on connections not being accepted, but it didn't help. I also added code to clear the SSL errors but they also had no influence.

What I see is that on the first run of the script I get 80% failures, but if I run again I get 100% failures and it stays that way for any further run of the test script until restarted. I also see this in syslog:

Oct 10 12:31:01 node15 ./opensips[3141]: ERROR:proto_tls:tls_accept: New TLS connection from 1.2.3.4:40630 failed to accept
Oct 10 12:31:01 node15 ./opensips[3141]: ERROR:proto_tls:tls_read_req: failed to do pre-tls reading

which indicates that the TLS context is corrupted and can't decrypt the message.

All this takes me back to my original question: is a TLS context that is created in a process, end up being used by another process? My suspicion right now is that is the case. One process allocates the TLS context and openssl allocates some thread specific cryptographic data used for the key exchange and encryption. If that TLS context ends up in another process afterwards, when openssl tries to fetch the thread specific crypto data it gets something else and it cannot decrypt the data anymore hence the syslog messages.

I tested this by running opensips with a single TCP worker and the problem goes away. 2 workers and I get an initial failure rate of 15%. 5 workers with autoscaling up to 25 and I get 80% initial failure rate. The more workers, the higher the initial failure rate is.

This can be further confirmed by trying to add some code that always sends the same connection to the same worker (so that the per process allocated internal crypto data is consistent) and see if that eliminates the problem.

razvancrainea commented 4 years ago

@danpascu no, the TLS context is not moved to a different process, at least not in this scenario. The context is only moved if a connection stays more than 5 seconds in the same process, but in our scenarios, the test doesn't last more than a couple of seconds altogether. My assumption is that OpenSSL allocates some data that should be private, but it somehow gets to be shared. But unfortunately I can't pinpoint that data :|.

The further I could go is the following scenario: I create two connections that are handled by two different processes: both processes read the SSL header correctly (365 bytes I believe), but after that, the read of successful connection returns 5 bytes, in the other it returns 0 bytes, as if the connection has been closed. That's where I got stuck...

danpascu commented 4 years ago

It seems your patch doesn't overwrite all call to those pthread functions, only some. Here is the output of what happens in TCP main and the TCP worker during a single connection that sends an OPTIONS and receives back a 200 OK. As you can see, every time the code calls the original pthread_rwlock_init, in turn it calls the original pthread_getspecific. I'm not sure if having this mix of original and overwritten pthread functions is problematic or not. Here is the gdb backtrace: output_thread.txt

danpascu commented 4 years ago

Another thing, I run the test script while monitoring in gdb all processes involved with TCP networking and I noticed 2 things:

  1. Only 3 out of 100 failed, but everything was a lot slower since gdb printed backtraces every time one of the overwritten pthread functions was called. It seems to be a timing issue that is helped when things are not that fast.

  2. Ony pthread_getspecific was called. Which makes me wonder who calls pthread_key_create, pthread_key_destroy and pthread_setspecific? Because none of them were called by making new connections. If these are only called when the SSL context is created, that makes me wonder how it works considering that the SSL context is created once per TLS domain in the attendant process and then inherited by all child process which would suggest that all thread specific data must be wrong/non-existent in all processes except the one that set that thread specific data which is the attendant before fork. This makes it even more confusing because it's not clear why it even failed in the first place before overwriting the pthread functions for thread specific data.

vitalikvoip commented 4 years ago

FYI, the "other" fork of SER has fixed the issue by setting different PseudoRandomNumberGenerator and also by using the standard one but wrapping it with lock()/unlock(). The direction you took with overriding thread specific related functions looks more correct since, in theory, it can help to avoid problems in other parts of libssl which may use thread specific data. But maybe while the correct fix is in development opensips can adopt PRNG overriding solution.

razvancrainea commented 4 years ago

Indeed, it looks like overriding the PRNG can sort this out. I will try to devel this in the following days, as soon as I get some free time. Will keep you updated with my progress.

razvancrainea commented 4 years ago

Bad news - I did try to add some locking on top of the PRNG openssl library. Although it no longer crashes, it has the same behavior as the the patch I've done (overwriting the TLS mechanism) - roughly the same number of connections get rejected. So the main problem is still there.

After doing some more research on this matter, it simply looks like openssl is not able to read the entire SSL packet sent on the network, that's why it is not able to accept the connection. But frankly, I don't know how this is happening, still need more effort to investigate.

danpascu commented 4 years ago

Unfortunately the number of rejected connections always reaches 100%. It only starts at 70-80% when you use the test script, but if you use it again you get 100%. Every connection that gets corrupted never recovers and next time a new one gets corrupted when parallel TLS processing happens until all workers get corrupted.

stale[bot] commented 4 years ago

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.

razvancrainea commented 4 years ago

Hold on, stale, this is not yet resolved.

razvancrainea commented 4 years ago

I've finally managed to find some time to look deeper into this issue, and I think I got to the bottom of it. Could you please try commit 1bc5cd87, and let me know if there are any other issues regarding SSL?

danpascu commented 4 years ago

Latest changes seem to have fixed the issues for me. Thanks for the fix @razvancrainea

razvancrainea commented 4 years ago

Awesome! I will leave a couple of days the fix only on master, to see if there are any side effects. After that, if all goes well, I will backport the changes down to 2.4 and close the ticket.

Thanks a lot @danpascu for your support on this issue!

vitalikvoip commented 4 years ago

I applied this patch to 2.4 and in the beginning load test had no problems but after I restarted it a couple of times opensips started to drop TLS connection:

Jan 9 16:12:59 in1.ifctest.net--voip-proxy /usr/sbin/opensips[24227]: ERROR:proto_tls:tls_accept: New TLS connection from 188.130.177.214:15858 failed to accept Jan 9 16:12:59 in1.ifctest.net--voip-proxy /usr/sbin/opensips[24227]: ERROR:proto_tls:tls_print_errstack: TLS errstack: error:1409441B:SSL routines:ssl3_read_bytes:tlsv1 alert decrypt error Jan 9 16:12:59 in1.ifctest.net--voip-proxy /usr/sbin/opensips[24227]: ERROR:proto_tls:tls_read_req: failed to do pre-tls reading

I added log lines to new crypto wrappers and saw that only *os_ssl_bytes" was called actively.

Verified once again and updated my customized branch from the official 2.4 branch, applied 1bc5cd8 from master branch and still have the problem. If it works with master version I suppose it can have other important changes which were not backported to 2.4.

razvancrainea commented 4 years ago

Did the patches apply normally, or were there any conflicts? Are you experiencing the same issue with 3.1? I was planning to wait a while for you guys to fully check 3.1, and then backport the fix to 2.4 after a couple of days.

vitalikvoip commented 4 years ago

I manually copied all you added by the patch and added logs to all functions (both rand methods and ssl_tweaks.h) just to make sure all code is used and libssl version detected correctly. Unfortunately have no environment to test 3.1. I have a bunch of patches which are verified on 2.4 and it will take some time to merge them into 3.1

danpascu commented 4 years ago

@vitalikvoip I think it was a collection of patches that solved the problem it wasn't just 1bc5cd8 alone that fixed it. As far as I understand 97c0a27 which created the SSL context per process together with b54ccb2 was also part of the fix and I think 3d508e7 was too.

vitalikvoip commented 4 years ago

Thanks for the hint. That what I was thinking about. tls_mgm of the master branch has lots of changes comparing to 2.4. Checking the diff.

vitalikvoip commented 4 years ago

As a proof of concept, I backported (with lots of ugly hacks, to make it compatible with old codebase) tls_mgm module from the master (3.1) branch to my 2.4 and load testing shows that tls is pretty stable so the fix does its job well. Will try to backport only required patched instead of the whole module.

razvancrainea commented 4 years ago

@vitalikvoip awesome, thanks for confirming! I am planning to do the backport down to 2.4 myself ASAP, will let you know when its done.

razvancrainea commented 4 years ago

I've just finished porting the module for all branches. Please give it a try and let me know if you encounter any issues. If you want to find out more information about this bug, I've also written a blog post that contains more details about the bug and the solution.

vitalikvoip commented 4 years ago

Checked 2.4 patches and had no problems during load testing. BTW, tls related code is not async, right?

razvancrainea commented 4 years ago

Nope, it is not async, yet :).