[SR-Users] kamailio 5.4.3 ubuntu 20.04 tls - http_async_client

Tue Jan 26 15:39:20 CET 2021

Hello,

would you be able to test on Debian 10 (maybe using docker or virtual
machine/virtualbox) and see if you get the same issue?

I do not have Ubuntu 20.04 at hand and I haven't encountered any issue
lately with tls on Debian 10. In this way we can rule out if it is
specific to Ubuntu version of the libraries or not.

Cheers,
Daniel

On 26.01.21 15:06, Filippo Graziola wrote:
> Hi all,
> I have an issue related (my guess) to tls and http_async_client module
> that result in a segmentation fault and a not correct handle of tls
> connections.
>
> First with only tls module loaded, not forked:
>
>  0(1021) INFO: <core> [core/tcp_main.c:4983]: init_tcp(): using
> epoll_lt as the io watch method (auto detected)
>  0(1021) INFO: rr [../outbound/api.h:52]: ob_load_api(): unable to
> import bind_ob - maybe module is not loaded
>  0(1021) INFO: rr [rr_mod.c:185]: mod_init(): outbound module not
> available
>  0(1021) INFO: tls [tls_mod.c:389]: mod_init(): With ECDH-Support!
>  0(1021) INFO: tls [tls_mod.c:392]: mod_init(): With Diffie Hellman
>  0(1021) WARNING: tls [tls_init.c:784]: tls_h_mod_init_f(): openssl
> bug #1491 (crash/mem leaks on low memory) workaround enabled (on low
> memory tls operations will fail preemptively) with free memory
> thresholds 4718592 and 2359296 bytes
>  0(1021) INFO: <core> [core/cfg/cfg_ctx.c:595]: cfg_set_now():
> tls.low_mem_threshold1 has been changed to 4718592
>  0(1021) INFO: <core> [core/cfg/cfg_ctx.c:595]: cfg_set_now():
> tls.low_mem_threshold2 has been changed to 2359296
>  0(1021) INFO: <core> [main.c:2833]: main(): processes (at least): 9 -
> shm size: 67108864 - pkg size: 67108864
>  0(1021) INFO: <core> [core/udp_server.c:154]:
> probe_max_receive_buffer(): SO_RCVBUF is initially 212992
>  0(1021) INFO: <core> [core/udp_server.c:206]:
> probe_max_receive_buffer(): SO_RCVBUF is finally 425984
>  0(1021) INFO: tls [tls_domain.c:305]: ksr_tls_fill_missing():
> TLSs<default>: tls_method=12
>  0(1021) INFO: tls [tls_domain.c:317]: ksr_tls_fill_missing():
> TLSs<default>: certificate='/etc/kamailio/fullchain.pem'
>  0(1021) INFO: tls [tls_domain.c:324]: ksr_tls_fill_missing():
> TLSs<default>: ca_list='(null)'
>  0(1021) INFO: tls [tls_domain.c:331]: ksr_tls_fill_missing():
> TLSs<default>: crl='(null)'
>  0(1021) INFO: tls [tls_domain.c:334]: ksr_tls_fill_missing():
> TLSs<default>: require_certificate=0
>  0(1021) INFO: tls [tls_domain.c:342]: ksr_tls_fill_missing():
> TLSs<default>: cipher_list='(null)'
>  0(1021) INFO: tls [tls_domain.c:349]: ksr_tls_fill_missing():
> TLSs<default>: private_key='/etc/kamailio/privkey.pem'
>  0(1021) INFO: tls [tls_domain.c:352]: ksr_tls_fill_missing():
> TLSs<default>: verify_certificate=0
>  0(1021) INFO: tls [tls_domain.c:356]: ksr_tls_fill_missing():
> TLSs<default>: verify_depth=9
>  0(1021) INFO: tls [tls_domain.c:359]: ksr_tls_fill_missing():
> TLSs<default>: verify_client=0
>  0(1021) NOTICE: tls [tls_domain.c:1105]: ksr_tls_fix_domain():
> registered server_name callback handler for socket [:0],
> server_name='<default>' ...
>  0(1021) INFO: tls [tls_domain.c:711]: set_verification():
> TLSs<default>: No client certificate required and no checks performed
>  0(1021) INFO: tls [tls_domain.c:305]: ksr_tls_fill_missing():
> TLSc<default>: tls_method=20
>  0(1021) INFO: tls [tls_domain.c:317]: ksr_tls_fill_missing():
> TLSc<default>: certificate='(null)'
>  0(1021) INFO: tls [tls_domain.c:324]: ksr_tls_fill_missing():
> TLSc<default>: ca_list='(null)'
>  0(1021) INFO: tls [tls_domain.c:331]: ksr_tls_fill_missing():
> TLSc<default>: crl='(null)'
>  0(1021) INFO: tls [tls_domain.c:334]: ksr_tls_fill_missing():
> TLSc<default>: require_certificate=0
>  0(1021) INFO: tls [tls_domain.c:342]: ksr_tls_fill_missing():
> TLSc<default>: cipher_list='(null)'
>  0(1021) INFO: tls [tls_domain.c:349]: ksr_tls_fill_missing():
> TLSc<default>: private_key='(null)'
>  0(1021) INFO: tls [tls_domain.c:352]: ksr_tls_fill_missing():
> TLSc<default>: verify_certificate=0
>  0(1021) INFO: tls [tls_domain.c:356]: ksr_tls_fill_missing():
> TLSc<default>: verify_depth=9
>  0(1021) INFO: tls [tls_domain.c:359]: ksr_tls_fill_missing():
> TLSc<default>: verify_client=0
>  0(1021) INFO: tls [tls_domain.c:714]: set_verification():
> TLSc<default>: Server MAY present invalid certificate
>  6(1027) ERROR: tls [tls_server.c:1283]: tls_h_read_f(): protocol
> level error
>  6(1027) ERROR: tls [tls_util.h:42]: tls_err_ret(): TLS
> accept:error:141FC044:SSL routines:tls_setup_handshake:internal error
>  6(1027) ERROR: tls [tls_server.c:1287]: tls_h_read_f(): source IP:
> XXXXXXXXXXXXXXX
>  6(1027) ERROR: tls [tls_server.c:1290]: tls_h_read_f(): destination
> IP: XXXXXXXXXX
>  6(1027) ERROR: <core> [core/tcp_read.c:1498]: tcp_read_req(): ERROR:
> tcp_read_req: error reading - c: 0x7f2cbc1b3948 r: 0x7f2cbc1b3a70 (-1)
>
> so no segmentation fault but error in handling.
>
> Second one also with http_async_client loaded:
>
>  0(1059) INFO: <core> [core/tcp_main.c:4983]: init_tcp(): using
> epoll_lt as the io watch method (auto detected)
>  0(1061) INFO: rr [../outbound/api.h:52]: ob_load_api(): unable to
> import bind_ob - maybe module is not loaded
>  0(1061) INFO: rr [rr_mod.c:185]: mod_init(): outbound module not
> available
>  0(1061) INFO: tls [tls_mod.c:389]: mod_init(): With ECDH-Support!
>  0(1061) INFO: tls [tls_mod.c:392]: mod_init(): With Diffie Hellman
>  0(1061) INFO: http_async_client [http_async_client_mod.c:222]:
> mod_init(): Initializing Http Async module
>  0(1061) WARNING: tls [tls_init.c:784]: tls_h_mod_init_f(): openssl
> bug #1491 (crash/mem leaks on low memory) workaround enabled (on low
> memory tls operations will fail preemptively) with free memory
> thresholds 5242880 and 2621440 bytes
>  0(1061) INFO: <core> [core/cfg/cfg_ctx.c:595]: cfg_set_now():
> tls.low_mem_threshold1 has been changed to 5242880
>  0(1061) INFO: <core> [core/cfg/cfg_ctx.c:595]: cfg_set_now():
> tls.low_mem_threshold2 has been changed to 2621440
>  0(1061) INFO: <core> [main.c:2833]: main(): processes (at least): 10
> - shm size: 67108864 - pkg size: 67108864
>  0(1061) INFO: <core> [core/udp_server.c:154]:
> probe_max_receive_buffer(): SO_RCVBUF is initially 212992
>  0(1061) INFO: <core> [core/udp_server.c:206]:
> probe_max_receive_buffer(): SO_RCVBUF is finally 425984
>  0(1061) INFO: tls [tls_domain.c:305]: ksr_tls_fill_missing():
> TLSs<default>: tls_method=12
>  0(1061) INFO: tls [tls_domain.c:317]: ksr_tls_fill_missing():
> TLSs<default>: certificate='/etc/kamailio/fullchain.pem'
>  0(1061) INFO: tls [tls_domain.c:324]: ksr_tls_fill_missing():
> TLSs<default>: ca_list='(null)'
>  0(1061) INFO: tls [tls_domain.c:331]: ksr_tls_fill_missing():
> TLSs<default>: crl='(null)'
>  0(1061) INFO: tls [tls_domain.c:334]: ksr_tls_fill_missing():
> TLSs<default>: require_certificate=0
>  0(1061) INFO: tls [tls_domain.c:342]: ksr_tls_fill_missing():
> TLSs<default>: cipher_list='(null)'
>  0(1061) INFO: tls [tls_domain.c:349]: ksr_tls_fill_missing():
> TLSs<default>: private_key='/etc/kamailio/privkey.pem'
>  0(1061) INFO: tls [tls_domain.c:352]: ksr_tls_fill_missing():
> TLSs<default>: verify_certificate=0
>  0(1061) INFO: tls [tls_domain.c:356]: ksr_tls_fill_missing():
> TLSs<default>: verify_depth=9
>  0(1061) INFO: tls [tls_domain.c:359]: ksr_tls_fill_missing():
> TLSs<default>: verify_client=0
>  0(1061) NOTICE: tls [tls_domain.c:1105]: ksr_tls_fix_domain():
> registered server_name callback handler for socket [:0],
> server_name='<default>' ...
>  0(1061) INFO: tls [tls_domain.c:711]: set_verification():
> TLSs<default>: No client certificate required and no checks performed
>  0(1061) INFO: tls [tls_domain.c:305]: ksr_tls_fill_missing():
> TLSc<default>: tls_method=20
>  0(1061) INFO: tls [tls_domain.c:317]: ksr_tls_fill_missing():
> TLSc<default>: certificate='(null)'
>  0(1061) INFO: tls [tls_domain.c:324]: ksr_tls_fill_missing():
> TLSc<default>: ca_list='(null)'
>  0(1061) INFO: tls [tls_domain.c:331]: ksr_tls_fill_missing():
> TLSc<default>: crl='(null)'
>  0(1061) INFO: tls [tls_domain.c:334]: ksr_tls_fill_missing():
> TLSc<default>: require_certificate=0
>  0(1061) INFO: tls [tls_domain.c:342]: ksr_tls_fill_missing():
> TLSc<default>: cipher_list='(null)'
>  0(1061) INFO: tls [tls_domain.c:349]: ksr_tls_fill_missing():
> TLSc<default>: private_key='(null)'
>  0(1061) INFO: tls [tls_domain.c:352]: ksr_tls_fill_missing():
> TLSc<default>: verify_certificate=0
>  0(1061) INFO: tls [tls_domain.c:356]: ksr_tls_fill_missing():
> TLSc<default>: verify_depth=9
>  0(1061) INFO: tls [tls_domain.c:359]: ksr_tls_fill_missing():
> TLSc<default>: verify_client=0
>  0(1061) INFO: tls [tls_domain.c:714]: set_verification():
> TLSc<default>: Server MAY present invalid certificate
>  0(1061) INFO: http_async_client [async_http.c:101]:
> async_http_init_sockets(): inter-process event notification sockets
> initialized
>  0(1061) INFO: http_async_client [async_http.c:84]:
> async_http_init_worker(): started worker process: 1
>  0(1059) CRITICAL: <core> [core/mem/q_malloc.c:501]: qm_free(): BUG:
> bad pointer 0x1 (out of memory block!) called from tls: tls_init.c:
> ser_free(323) - ignoring
> Segmentation fault
>
> this time, there is a segmentation fault.
> The above is a result of this minimal configuration: 
>
> #!KAMAILIO
>
> ####### Global Parameters #########
>
> /* LOG Levels: 3=DBG, 2=INFO, 1=NOTICE, 0=WARN, -1=ERR, ... */
> debug=2
> log_stderror=no
> memdbg=5
> memlog=5
>
> log_facility=LOG_LOCAL0
> log_prefix="{$mt $hdr(CSeq) $ci} "
>
> children=2
> tcp_children=2
> auto_aliases=no
> alias="XXXXXXXXXXXXX"
>
> listen=udp:eth0
> server_signature=no
> tcp_connection_lifetime=3605
> tcp_max_connections=40960
> tcp_accept_no_cl=yes
> enable_tls=yes
> listen=tls:XXXXXXXXXX:5061 advertise XXXXXXXXXXXX:5061
> tls_max_connections=40000
> enable_sctp=no
>
> ####### Modules Section ########
>
> loadmodule "kex.so"
> loadmodule "corex.so"
> loadmodule "tm.so"
> loadmodule "tmx.so"
> loadmodule "sl.so"
> loadmodule "rr.so"
> loadmodule "pv.so"
> loadmodule "tls.so"
> loadmodule "http_async_client.so"
>
> #----------------- setting module-specific parameters ---------------
> #----- tls params -----
> modparam("tls", "config", "/etc/kamailio/tls.cfg")
>
> #----- http client ----
> modparam("http_async_client", "workers", 1)
>
> ####### Routing Logic ########
>
> request_route {
> exit;
> }
>
> I used the above configuration to take out as much as possible my
> mistakes in the configuration, but with my full kamailio
> configuration, tls connections give the above errors but everything
> else works just fine (also http_async_client module functions which
> are used on INVITES) and calls are going properly (unfortunately tls
> is required). 
> I found a couple of issues that are
> similar https://github.com/kamailio/kamailio/issues/2560
> <https://github.com/kamailio/kamailio/issues/2560>
> and https://github.com/kamailio/kamailio/issues/2466#
> <https://github.com/kamailio/kamailio/issues/2466#> but as far as I
> understood the issue 2466 is closed because fixes are already
> included. I tried in any case to compile from source a few older
> releases with the same result, changed also the certificate and
> private key (letsencrypt), moreover I have another kamailio (v5.3.4)
> running on ubuntu 18.04 (same configuration) without any issues. I saw
> that there is a different version of openssl version 1.0.. in ubuntu
> 18.04, version 1.1 in ubuntu 20.04, but the segmentation fault seems
> to happen after an error on free some memory. 
> Have you some ideas? tell me if you need more info from me. 
>
> Thanks
> Filippo
>
> _______________________________________________
> Kamailio (SER) - Users Mailing List
> sr-users at lists.kamailio.org
> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users

-- 
Daniel-Constantin Mierla -- www.asipto.com
www.twitter.com/miconda -- www.linkedin.com/in/miconda
Funding: https://www.paypal.me/dcmierla

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20210126/a4cf0af6/attachment.htm>