Hi,
I'm trying to add tls to our services, but seem hindered by "something". When enabling the tls module it seems to turn off the SSL setting in postgresql, and since we require SSL on our postgres servers Kamailio can't connect and it fails to start.
If I disable WITH_TLS it will start. If I comment out the sqlops modparam it will also start.
Kamailio on RHEL6, from ~4.1.6 git rev 2f690887b45dbc49a8038b1fa041d47cd9ae39ea.
# kamailio -V version: kamailio 4.1.6 (x86_64/linux) flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled on 16:48:10 Sep 26 2014 with gcc 4.4.7
Very simpel config file:
debug=3 log_stderror=no log_facility=LOG_LOCAL0
fork=yes children=2
#!define TLSFILE "/kamailio/tls-fooserver1.cfg"
port=5060
#!define WITH_TLS #!ifdef WITH_TLS enable_tls=yes #!endif
include_file "/kamailio/databases.cfg"
loadmodule "tm.so" # Transaction (stateful) module loadmodule "tmx.so" # Extensions from Kamailio TM module loadmodule "sl.so" # Stateless replier module loadmodule "rr.so" # Record-Route and Route module loadmodule "pv.so" # Module holding Pseudo-Variables loadmodule "sqlops.so" # SQL operations
loadmodule "db_postgres.so" # POSTGRES-backend for database API module
#!ifdef WITH_TLS loadmodule "tls.so" #!endif
modparam("sqlops","sqlcon",SQLOPS_DATA)
#!ifdef WITH_TLS modparam("tls", "config", TLSFILE) #!endif
route{ exit; }
SQLOPS_DATA is just a normal "data=>postgres://user:pass@server/db".
TLSFILE contains: [server:default] method = TLSv1 verify_certificate = no require_certificate = no private_key = /ssl/key certificate = /ssl/cert ca_list = /ssl/terena_chain2.pem
[client:default] verify_certificate = no require_certificate = no
From messages on startup:
Dec 15 13:50:19 fooserver1 kamailio[12115]: INFO: tls [tls_init.c:385]: init_tls_compression(): tls: init_tls: disabling compression... Dec 15 13:50:19 fooserver1 kamailio[12115]: INFO: <core> [tcp_main.c:4836]: init_tcp(): init_tcp: using epoll_lt as the io watch method (auto detected) Dec 15 13:50:19 fooserver1 kamailio[12118]: WARNING: <core> [daemonize.c:352]: daemonize(): pid file contains old pid, replacing pid Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: rr [../outbound/api.h:54]: ob_load_api(): Failed to import bind_ob Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: rr [rr_mod.c:159]: mod_init(): outbound module not available Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_mod.c:346]: mod_init(): With ECDH-Support! Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_mod.c:349]: mod_init(): With Diffie Hellman Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_init.c:549]: init_tls_h(): tls: _init_tls_h: compiled with openssl version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, compression: on Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_init.c:557]: init_tls_h(): tls: init_tls_h: installed openssl library version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, zlib compression: on#012 compiler: gcc -fPIC -DO PENSSL_PIC -DZLIB -DOPENSSL_THREADS -D_REENTRANT -DDSO_DLFCN -DHAVE_DLFCN_H -DKRB5_MIT -m64 -DL_ENDIAN -DTERMIO -Wall -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector --param=ssp-buffer-size=4 -m64 -mtune=generic -Wa,--noexecstack -DPURIFY -DOPEN SSL_IA32_SSE2 -DOPENSSL_BN_ASM_MONT -DOPENSSL_BN_ASM_MONT5 -DOPENSSL_BN_ASM_GF2m -DSHA1_ASM -DSHA256_ASM -DSHA512_ASM -DMD5_ASM -DAES_ASM -DVPAES_ASM -DBSAES_ASM -DWHIRLPOOL_ASM -DGHASH_ASM Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: WARNING: tls [tls_init.c:611]: init_tls_h(): tls: 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 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [cfg/cfg_ctx.c:613]: cfg_set_now(): INFO: cfg_set_now(): tls.low_mem_threshold1 has been changed to 5242880 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [cfg/cfg_ctx.c:613]: cfg_set_now(): INFO: cfg_set_now(): tls.low_mem_threshold2 has been changed to 2621440 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:176]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is initially 124928 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:227]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is finally 249856 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:176]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is initially 124928 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:227]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is finally 249856 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:275]: fill_missing(): TLSs<default>: tls_method=9 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:287]: fill_missing(): TLSs<default>: certificate='/path/ssl/fooserver1.uio.no.crt' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:294]: fill_missing(): TLSs<default>: ca_list='/voip/packages/mgmt/ssl/terena_chain2.pem' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:301]: fill_missing(): TLSs<default>: crl='(null)' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:305]: fill_missing(): TLSs<default>: require_certificate=0 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:312]: fill_missing(): TLSs<default>: cipher_list='(null)' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:319]: fill_missing(): TLSs<default>: private_key='/path/ssl/fooserver1.uio.no.key' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:323]: fill_missing(): TLSs<default>: verify_certificate=0 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:326]: fill_missing(): TLSs<default>: verify_depth=9 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:670]: set_verification(): TLSs<default>: No client certificate required and no checks performed Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:275]: fill_missing(): TLSc<default>: tls_method=9 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:287]: fill_missing(): TLSc<default>: certificate='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:294]: fill_missing(): TLSc<default>: ca_list='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:301]: fill_missing(): TLSc<default>: crl='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:305]: fill_missing(): TLSc<default>: require_certificate=0 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:312]: fill_missing(): TLSc<default>: cipher_list='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:319]: fill_missing(): TLSc<default>: private_key='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:323]: fill_missing(): TLSc<default>: verify_certificate=0 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:326]: fill_missing(): TLSc<default>: verify_depth=9 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:673]: set_verification(): TLSc<default>: Server MAY present invalid certificate Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: db_postgres [km_pg_con.c:82]: db_postgres_new_connection(): SSL SYSCALL error: Resource temporarily unavailable#012FATAL: no pg_hba.conf entry for host "129.240.1.1", user "foo_test_user", database " foo_test", SSL off#012 Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: db_postgres [km_pg_con.c:95]: db_postgres_new_connection(): cleaning up 0x7fce98be0c78=pkg_free() Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [db.c:322]: db_do_init2(): could not add connection to the pool Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: sqlops [sql_api.c:166]: sql_connect(): failed to connect to the database [data] Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [sr_module.c:927]: init_mod_child(): init_mod_child(): Error while initializing module sqlops (/usr/lib64/kamailio/modules/sqlops.so) Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [pt.c:490]: fork_tcp_process(): ERROR: fork_tcp_process(): init_child failed for process 7, pid 12125, "tcp receiver (generic) child=0" Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [tcp_main.c:4962]: tcp_init_children(): ERROR: tcp_main: fork failed: Success Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12118]: ALERT: <core> [main.c:774]: handle_sigs(): child process 12125 exited normally, status=255 Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [main.c:792]: handle_sigs(): INFO: terminating due to SIGCHLD Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12126]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12124]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12123]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12122]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12121]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12120]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12127]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received
Any ideas?
Best regards, Øyvind
Hello,
I see the error is:
Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: db_postgres [km_pg_con.c:82]: db_postgres_new_connection(): SSL SYSCALL error: Resource temporarily unavailable#012FATAL: no pg_hba.conf entry for host "129.240.1.1", user "foo_test_user", database " foo_test", SSL off#012
TLS module is initializing the libssl instance, because it needs to set the shared memory manager for handling tls connections. It was working fine so far.
Can you get more from the above log message related to postgres? TLS module initializes ok.
Cheers, Daniel
On 15/12/14 14:03, Øyvind Kolbu wrote:
Hi,
I'm trying to add tls to our services, but seem hindered by "something". When enabling the tls module it seems to turn off the SSL setting in postgresql, and since we require SSL on our postgres servers Kamailio can't connect and it fails to start.
If I disable WITH_TLS it will start. If I comment out the sqlops modparam it will also start.
Kamailio on RHEL6, from ~4.1.6 git rev 2f690887b45dbc49a8038b1fa041d47cd9ae39ea.
# kamailio -V version: kamailio 4.1.6 (x86_64/linux) flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled on 16:48:10 Sep 26 2014 with gcc 4.4.7
Very simpel config file:
debug=3 log_stderror=no log_facility=LOG_LOCAL0
fork=yes children=2
#!define TLSFILE "/kamailio/tls-fooserver1.cfg"
port=5060
#!define WITH_TLS #!ifdef WITH_TLS enable_tls=yes #!endif
include_file "/kamailio/databases.cfg"
loadmodule "tm.so" # Transaction (stateful) module loadmodule "tmx.so" # Extensions from Kamailio TM module loadmodule "sl.so" # Stateless replier module loadmodule "rr.so" # Record-Route and Route module loadmodule "pv.so" # Module holding Pseudo-Variables loadmodule "sqlops.so" # SQL operations
loadmodule "db_postgres.so" # POSTGRES-backend for database API module
#!ifdef WITH_TLS loadmodule "tls.so" #!endif
modparam("sqlops","sqlcon",SQLOPS_DATA)
#!ifdef WITH_TLS modparam("tls", "config", TLSFILE) #!endif
route{ exit; }
SQLOPS_DATA is just a normal "data=>postgres://user:pass@server/db".
TLSFILE contains: [server:default] method = TLSv1 verify_certificate = no require_certificate = no private_key = /ssl/key certificate = /ssl/cert ca_list = /ssl/terena_chain2.pem
[client:default] verify_certificate = no require_certificate = no
From messages on startup:
Dec 15 13:50:19 fooserver1 kamailio[12115]: INFO: tls [tls_init.c:385]: init_tls_compression(): tls: init_tls: disabling compression... Dec 15 13:50:19 fooserver1 kamailio[12115]: INFO: <core> [tcp_main.c:4836]: init_tcp(): init_tcp: using epoll_lt as the io watch method (auto detected) Dec 15 13:50:19 fooserver1 kamailio[12118]: WARNING: <core> [daemonize.c:352]: daemonize(): pid file contains old pid, replacing pid Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: rr [../outbound/api.h:54]: ob_load_api(): Failed to import bind_ob Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: rr [rr_mod.c:159]: mod_init(): outbound module not available Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_mod.c:346]: mod_init(): With ECDH-Support! Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_mod.c:349]: mod_init(): With Diffie Hellman Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_init.c:549]: init_tls_h(): tls: _init_tls_h: compiled with openssl version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, compression: on Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_init.c:557]: init_tls_h(): tls: init_tls_h: installed openssl library version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, zlib compression: on#012 compiler: gcc -fPIC -DO PENSSL_PIC -DZLIB -DOPENSSL_THREADS -D_REENTRANT -DDSO_DLFCN -DHAVE_DLFCN_H -DKRB5_MIT -m64 -DL_ENDIAN -DTERMIO -Wall -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector --param=ssp-buffer-size=4 -m64 -mtune=generic -Wa,--noexecstack -DPURIFY -DOPEN SSL_IA32_SSE2 -DOPENSSL_BN_ASM_MONT -DOPENSSL_BN_ASM_MONT5 -DOPENSSL_BN_ASM_GF2m -DSHA1_ASM -DSHA256_ASM -DSHA512_ASM -DMD5_ASM -DAES_ASM -DVPAES_ASM -DBSAES_ASM -DWHIRLPOOL_ASM -DGHASH_ASM Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: WARNING: tls [tls_init.c:611]: init_tls_h(): tls: 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 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [cfg/cfg_ctx.c:613]: cfg_set_now(): INFO: cfg_set_now(): tls.low_mem_threshold1 has been changed to 5242880 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [cfg/cfg_ctx.c:613]: cfg_set_now(): INFO: cfg_set_now(): tls.low_mem_threshold2 has been changed to 2621440 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:176]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is initially 124928 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:227]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is finally 249856 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:176]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is initially 124928 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:227]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is finally 249856 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:275]: fill_missing(): TLSs<default>: tls_method=9 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:287]: fill_missing(): TLSs<default>: certificate='/path/ssl/fooserver1.uio.no.crt' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:294]: fill_missing(): TLSs<default>: ca_list='/voip/packages/mgmt/ssl/terena_chain2.pem' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:301]: fill_missing(): TLSs<default>: crl='(null)' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:305]: fill_missing(): TLSs<default>: require_certificate=0 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:312]: fill_missing(): TLSs<default>: cipher_list='(null)' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:319]: fill_missing(): TLSs<default>: private_key='/path/ssl/fooserver1.uio.no.key' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:323]: fill_missing(): TLSs<default>: verify_certificate=0 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:326]: fill_missing(): TLSs<default>: verify_depth=9 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:670]: set_verification(): TLSs<default>: No client certificate required and no checks performed Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:275]: fill_missing(): TLSc<default>: tls_method=9 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:287]: fill_missing(): TLSc<default>: certificate='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:294]: fill_missing(): TLSc<default>: ca_list='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:301]: fill_missing(): TLSc<default>: crl='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:305]: fill_missing(): TLSc<default>: require_certificate=0 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:312]: fill_missing(): TLSc<default>: cipher_list='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:319]: fill_missing(): TLSc<default>: private_key='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:323]: fill_missing(): TLSc<default>: verify_certificate=0 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:326]: fill_missing(): TLSc<default>: verify_depth=9 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:673]: set_verification(): TLSc<default>: Server MAY present invalid certificate Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: db_postgres [km_pg_con.c:82]: db_postgres_new_connection(): SSL SYSCALL error: Resource temporarily unavailable#012FATAL: no pg_hba.conf entry for host "129.240.1.1", user "foo_test_user", database " foo_test", SSL off#012 Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: db_postgres [km_pg_con.c:95]: db_postgres_new_connection(): cleaning up 0x7fce98be0c78=pkg_free() Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [db.c:322]: db_do_init2(): could not add connection to the pool Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: sqlops [sql_api.c:166]: sql_connect(): failed to connect to the database [data] Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [sr_module.c:927]: init_mod_child(): init_mod_child(): Error while initializing module sqlops (/usr/lib64/kamailio/modules/sqlops.so) Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [pt.c:490]: fork_tcp_process(): ERROR: fork_tcp_process(): init_child failed for process 7, pid 12125, "tcp receiver (generic) child=0" Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [tcp_main.c:4962]: tcp_init_children(): ERROR: tcp_main: fork failed: Success Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12118]: ALERT: <core> [main.c:774]: handle_sigs(): child process 12125 exited normally, status=255 Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [main.c:792]: handle_sigs(): INFO: terminating due to SIGCHLD Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12126]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12124]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12123]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12122]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12121]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12120]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12127]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received
Any ideas?
Best regards, Øyvind
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
This is the last lines before the SYSCALL error: /usr/sbin/kamailio[30073]: DEBUG: db_postgres [km_pg_con.c:78]: db_postgres_new_connection(): PQsetdbLogin(0xbfe360) /usr/sbin/kamailio[30071]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e07395000, 100) called from tls: tls_init.c: ser_malloc(271)
These are all the db_postgres lines from the startup until crash:
Dec 16 09:51:11 fooserver1 kamailio[30067]: DEBUG: <core> [cfg.y:1635]: yyparse(): loading module db_postgres.so Dec 16 09:51:11 fooserver1 kamailio[30067]: DEBUG: <core> [sr_module.c:591]: load_module(): load_module: trying to load </usr/lib64/kamailio/modules/db_postgres.so> Dec 16 09:51:11 fooserver1 kamailio[30067]: DEBUG: <core> [cfg.lex:1703]: pp_define(): defining id: MOD_db_postgres Dec 16 09:51:12 fooserver1 /usr/sbin/kamailio[30070]: DEBUG: <core> [sr_module.c:966]: init_mod(): DEBUG: init_mod: db_postgres Dec 16 09:51:12 fooserver1 /usr/sbin/kamailio[30070]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e07395000, 80) called from db_postgres: ../../lock_alloc.h: lock_set_alloc(72) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30072]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30072]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30072]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30072]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30072]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218bd8=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30071]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30071]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30071]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30071]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30071]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218bd8=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30071]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30072]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30074]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30074]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30074]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30074]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30074]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218bd8=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30074]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218bd8=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30076]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30076]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30077]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30077]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30076]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30076]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30076]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218bd8=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30076]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30077]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30077]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30077]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218c78=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30077]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30078]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30075]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30075]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30078]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30075]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30075]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30075]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218bd8=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30075]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30078]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30078]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30078]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218c78=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30078]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:21 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: db_postgres [km_pg_con.c:78]: db_postgres_new_connection(): PQsetdbLogin(0xbfe360)
So it looks like it manages to create a few postgres connections before it calls PQsetdbLogin and then the next connection is rejected and Kamailio refuses to start.
Øyvind
On 15.12.2014 16:07, Daniel-Constantin Mierla wrote:
Hello,
I see the error is:
Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: db_postgres [km_pg_con.c:82]: db_postgres_new_connection(): SSL SYSCALL error: Resource temporarily unavailable#012FATAL: no pg_hba.conf entry for host "129.240.1.1", user "foo_test_user", database " foo_test", SSL off#012
TLS module is initializing the libssl instance, because it needs to set the shared memory manager for handling tls connections. It was working fine so far.
Can you get more from the above log message related to postgres? TLS module initializes ok.
Cheers, Daniel
On 15/12/14 14:03, Øyvind Kolbu wrote:
Hi,
I'm trying to add tls to our services, but seem hindered by "something". When enabling the tls module it seems to turn off the SSL setting in postgresql, and since we require SSL on our postgres servers Kamailio can't connect and it fails to start.
If I disable WITH_TLS it will start. If I comment out the sqlops modparam it will also start.
Kamailio on RHEL6, from ~4.1.6 git rev 2f690887b45dbc49a8038b1fa041d47cd9ae39ea.
# kamailio -V version: kamailio 4.1.6 (x86_64/linux) flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled on 16:48:10 Sep 26 2014 with gcc 4.4.7
Very simpel config file:
debug=3 log_stderror=no log_facility=LOG_LOCAL0
fork=yes children=2
#!define TLSFILE "/kamailio/tls-fooserver1.cfg"
port=5060
#!define WITH_TLS #!ifdef WITH_TLS enable_tls=yes #!endif
include_file "/kamailio/databases.cfg"
loadmodule "tm.so" # Transaction (stateful) module loadmodule "tmx.so" # Extensions from Kamailio TM module loadmodule "sl.so" # Stateless replier module loadmodule "rr.so" # Record-Route and Route module loadmodule "pv.so" # Module holding Pseudo-Variables loadmodule "sqlops.so" # SQL operations
loadmodule "db_postgres.so" # POSTGRES-backend for database API module
#!ifdef WITH_TLS loadmodule "tls.so" #!endif
modparam("sqlops","sqlcon",SQLOPS_DATA)
#!ifdef WITH_TLS modparam("tls", "config", TLSFILE) #!endif
route{ exit; }
SQLOPS_DATA is just a normal "data=>postgres://user:pass@server/db".
TLSFILE contains: [server:default] method = TLSv1 verify_certificate = no require_certificate = no private_key = /ssl/key certificate = /ssl/cert ca_list = /ssl/terena_chain2.pem
[client:default] verify_certificate = no require_certificate = no
From messages on startup:
Dec 15 13:50:19 fooserver1 kamailio[12115]: INFO: tls [tls_init.c:385]: init_tls_compression(): tls: init_tls: disabling compression... Dec 15 13:50:19 fooserver1 kamailio[12115]: INFO: <core> [tcp_main.c:4836]: init_tcp(): init_tcp: using epoll_lt as the io watch method (auto detected) Dec 15 13:50:19 fooserver1 kamailio[12118]: WARNING: <core> [daemonize.c:352]: daemonize(): pid file contains old pid, replacing pid Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: rr [../outbound/api.h:54]: ob_load_api(): Failed to import bind_ob Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: rr [rr_mod.c:159]: mod_init(): outbound module not available Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_mod.c:346]: mod_init(): With ECDH-Support! Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_mod.c:349]: mod_init(): With Diffie Hellman Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_init.c:549]: init_tls_h(): tls: _init_tls_h: compiled with openssl version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, compression: on Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_init.c:557]: init_tls_h(): tls: init_tls_h: installed openssl library version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, zlib compression: on#012 compiler: gcc -fPIC -DO PENSSL_PIC -DZLIB -DOPENSSL_THREADS -D_REENTRANT -DDSO_DLFCN -DHAVE_DLFCN_H -DKRB5_MIT -m64 -DL_ENDIAN -DTERMIO -Wall -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector --param=ssp-buffer-size=4 -m64 -mtune=generic -Wa,--noexecstack -DPURIFY -DOPEN SSL_IA32_SSE2 -DOPENSSL_BN_ASM_MONT -DOPENSSL_BN_ASM_MONT5 -DOPENSSL_BN_ASM_GF2m -DSHA1_ASM -DSHA256_ASM -DSHA512_ASM -DMD5_ASM -DAES_ASM -DVPAES_ASM -DBSAES_ASM -DWHIRLPOOL_ASM -DGHASH_ASM Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: WARNING: tls [tls_init.c:611]: init_tls_h(): tls: 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 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [cfg/cfg_ctx.c:613]: cfg_set_now(): INFO: cfg_set_now(): tls.low_mem_threshold1 has been changed to 5242880 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [cfg/cfg_ctx.c:613]: cfg_set_now(): INFO: cfg_set_now(): tls.low_mem_threshold2 has been changed to 2621440 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:176]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is initially 124928 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:227]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is finally 249856 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:176]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is initially 124928 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:227]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is finally 249856 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:275]: fill_missing(): TLSs<default>: tls_method=9 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:287]: fill_missing(): TLSs<default>: certificate='/path/ssl/fooserver1.uio.no.crt' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:294]: fill_missing(): TLSs<default>: ca_list='/voip/packages/mgmt/ssl/terena_chain2.pem' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:301]: fill_missing(): TLSs<default>: crl='(null)' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:305]: fill_missing(): TLSs<default>: require_certificate=0 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:312]: fill_missing(): TLSs<default>: cipher_list='(null)' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:319]: fill_missing(): TLSs<default>: private_key='/path/ssl/fooserver1.uio.no.key' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:323]: fill_missing(): TLSs<default>: verify_certificate=0 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:326]: fill_missing(): TLSs<default>: verify_depth=9 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:670]: set_verification(): TLSs<default>: No client certificate required and no checks performed Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:275]: fill_missing(): TLSc<default>: tls_method=9 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:287]: fill_missing(): TLSc<default>: certificate='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:294]: fill_missing(): TLSc<default>: ca_list='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:301]: fill_missing(): TLSc<default>: crl='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:305]: fill_missing(): TLSc<default>: require_certificate=0 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:312]: fill_missing(): TLSc<default>: cipher_list='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:319]: fill_missing(): TLSc<default>: private_key='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:323]: fill_missing(): TLSc<default>: verify_certificate=0 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:326]: fill_missing(): TLSc<default>: verify_depth=9 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:673]: set_verification(): TLSc<default>: Server MAY present invalid certificate Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: db_postgres [km_pg_con.c:82]: db_postgres_new_connection(): SSL SYSCALL error: Resource temporarily unavailable#012FATAL: no pg_hba.conf entry for host "129.240.1.1", user "foo_test_user", database " foo_test", SSL off#012 Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: db_postgres [km_pg_con.c:95]: db_postgres_new_connection(): cleaning up 0x7fce98be0c78=pkg_free() Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [db.c:322]: db_do_init2(): could not add connection to the pool Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: sqlops [sql_api.c:166]: sql_connect(): failed to connect to the database [data] Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [sr_module.c:927]: init_mod_child(): init_mod_child(): Error while initializing module sqlops (/usr/lib64/kamailio/modules/sqlops.so) Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [pt.c:490]: fork_tcp_process(): ERROR: fork_tcp_process(): init_child failed for process 7, pid 12125, "tcp receiver (generic) child=0" Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [tcp_main.c:4962]: tcp_init_children(): ERROR: tcp_main: fork failed: Success Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12118]: ALERT: <core> [main.c:774]: handle_sigs(): child process 12125 exited normally, status=255 Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [main.c:792]: handle_sigs(): INFO: terminating due to SIGCHLD Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12126]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12124]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12123]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12122]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12121]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12120]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12127]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received
Any ideas?
Best regards, Øyvind
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
The question would be more specific to the error message printed from postgres client library:
FATAL: no pg_hba.conf entry for host "129.240.1.1", user "foo_test_user", database " foo_test", SSL off
Is it something that is documented somewhere or maybe some web search can indicate the reasons why it happens?
Can you try loading tls module before db_postgres?
Cheers, Daniel
On 16/12/14 10:00, Øyvind Kolbu wrote:
This is the last lines before the SYSCALL error: /usr/sbin/kamailio[30073]: DEBUG: db_postgres [km_pg_con.c:78]: db_postgres_new_connection(): PQsetdbLogin(0xbfe360) /usr/sbin/kamailio[30071]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e07395000, 100) called from tls: tls_init.c: ser_malloc(271)
These are all the db_postgres lines from the startup until crash:
Dec 16 09:51:11 fooserver1 kamailio[30067]: DEBUG: <core> [cfg.y:1635]: yyparse(): loading module db_postgres.so Dec 16 09:51:11 fooserver1 kamailio[30067]: DEBUG: <core> [sr_module.c:591]: load_module(): load_module: trying to load </usr/lib64/kamailio/modules/db_postgres.so> Dec 16 09:51:11 fooserver1 kamailio[30067]: DEBUG: <core> [cfg.lex:1703]: pp_define(): defining id: MOD_db_postgres Dec 16 09:51:12 fooserver1 /usr/sbin/kamailio[30070]: DEBUG: <core> [sr_module.c:966]: init_mod(): DEBUG: init_mod: db_postgres Dec 16 09:51:12 fooserver1 /usr/sbin/kamailio[30070]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e07395000, 80) called from db_postgres: ../../lock_alloc.h: lock_set_alloc(72) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30072]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30072]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30072]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30072]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30072]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218bd8=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30071]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30071]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30071]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30071]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30071]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218bd8=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30071]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30072]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30074]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30074]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30074]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30074]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30074]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218bd8=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30074]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218bd8=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30076]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30076]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30077]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30077]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30076]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30076]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30076]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218bd8=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30076]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30077]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30077]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30077]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218c78=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30077]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30078]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30075]: DEBUG: <core> [sr_module.c:701]: find_mod_export_record(): find_export_record: found <db_bind_api> in module db_postgres [/usr/lib64/kamailio/modules/db_postgres.so] Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30075]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30078]: DEBUG: <core> [db.c:213]: db_bind_mod(): using db bind api for db_postgres Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30075]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30075]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30075]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218bd8=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30075]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30078]: DEBUG: db_postgres [km_pg_con.c:49]: db_postgres_new_connection(): db_id = 0x7f0e0d220a28 Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30078]: DEBUG: <core> [mem/q_malloc.c:369]: qm_malloc(): qm_malloc(0x7f0e0d1ce010, 80) called from db_postgres: km_pg_con.c: db_postgres_new_connection(56) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30078]: DEBUG: db_postgres [km_pg_con.c:62]: db_postgres_new_connection(): 0x7f0e0d218c78=pkg_malloc(80) Dec 16 09:51:16 fooserver1 /usr/sbin/kamailio[30078]: DEBUG: db_postgres [km_pg_con.c:74]: db_postgres_new_connection(): opening connection: postgres://xxxx:xxxx@fooserver2.uio.no/voip_test Dec 16 09:51:21 fooserver1 /usr/sbin/kamailio[30073]: DEBUG: db_postgres [km_pg_con.c:78]: db_postgres_new_connection(): PQsetdbLogin(0xbfe360)
So it looks like it manages to create a few postgres connections before it calls PQsetdbLogin and then the next connection is rejected and Kamailio refuses to start.
Øyvind
On 15.12.2014 16:07, Daniel-Constantin Mierla wrote:
Hello,
I see the error is:
Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: db_postgres [km_pg_con.c:82]: db_postgres_new_connection(): SSL SYSCALL error: Resource temporarily unavailable#012FATAL: no pg_hba.conf entry for host "129.240.1.1", user "foo_test_user", database " foo_test", SSL off#012
TLS module is initializing the libssl instance, because it needs to set the shared memory manager for handling tls connections. It was working fine so far.
Can you get more from the above log message related to postgres? TLS module initializes ok.
Cheers, Daniel
On 15/12/14 14:03, Øyvind Kolbu wrote:
Hi,
I'm trying to add tls to our services, but seem hindered by "something". When enabling the tls module it seems to turn off the SSL setting in postgresql, and since we require SSL on our postgres servers Kamailio can't connect and it fails to start.
If I disable WITH_TLS it will start. If I comment out the sqlops modparam it will also start.
Kamailio on RHEL6, from ~4.1.6 git rev 2f690887b45dbc49a8038b1fa041d47cd9ae39ea.
# kamailio -V version: kamailio 4.1.6 (x86_64/linux) flags: STATS: Off, USE_TCP, USE_TLS, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 4MB poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. id: unknown compiled on 16:48:10 Sep 26 2014 with gcc 4.4.7
Very simpel config file:
debug=3 log_stderror=no log_facility=LOG_LOCAL0
fork=yes children=2
#!define TLSFILE "/kamailio/tls-fooserver1.cfg"
port=5060
#!define WITH_TLS #!ifdef WITH_TLS enable_tls=yes #!endif
include_file "/kamailio/databases.cfg"
loadmodule "tm.so" # Transaction (stateful) module loadmodule "tmx.so" # Extensions from Kamailio TM module loadmodule "sl.so" # Stateless replier module loadmodule "rr.so" # Record-Route and Route module loadmodule "pv.so" # Module holding Pseudo-Variables loadmodule "sqlops.so" # SQL operations
loadmodule "db_postgres.so" # POSTGRES-backend for database API module
#!ifdef WITH_TLS loadmodule "tls.so" #!endif
modparam("sqlops","sqlcon",SQLOPS_DATA)
#!ifdef WITH_TLS modparam("tls", "config", TLSFILE) #!endif
route{ exit; }
SQLOPS_DATA is just a normal "data=>postgres://user:pass@server/db".
TLSFILE contains: [server:default] method = TLSv1 verify_certificate = no require_certificate = no private_key = /ssl/key certificate = /ssl/cert ca_list = /ssl/terena_chain2.pem
[client:default] verify_certificate = no require_certificate = no
From messages on startup:
Dec 15 13:50:19 fooserver1 kamailio[12115]: INFO: tls [tls_init.c:385]: init_tls_compression(): tls: init_tls: disabling compression... Dec 15 13:50:19 fooserver1 kamailio[12115]: INFO: <core> [tcp_main.c:4836]: init_tcp(): init_tcp: using epoll_lt as the io watch method (auto detected) Dec 15 13:50:19 fooserver1 kamailio[12118]: WARNING: <core> [daemonize.c:352]: daemonize(): pid file contains old pid, replacing pid Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: rr [../outbound/api.h:54]: ob_load_api(): Failed to import bind_ob Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: rr [rr_mod.c:159]: mod_init(): outbound module not available Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_mod.c:346]: mod_init(): With ECDH-Support! Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_mod.c:349]: mod_init(): With Diffie Hellman Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_init.c:549]: init_tls_h(): tls: _init_tls_h: compiled with openssl version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, compression: on Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_init.c:557]: init_tls_h(): tls: init_tls_h: installed openssl library version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, zlib compression: on#012 compiler: gcc -fPIC -DO PENSSL_PIC -DZLIB -DOPENSSL_THREADS -D_REENTRANT -DDSO_DLFCN -DHAVE_DLFCN_H -DKRB5_MIT -m64 -DL_ENDIAN -DTERMIO -Wall -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector --param=ssp-buffer-size=4 -m64 -mtune=generic -Wa,--noexecstack -DPURIFY -DOPEN SSL_IA32_SSE2 -DOPENSSL_BN_ASM_MONT -DOPENSSL_BN_ASM_MONT5 -DOPENSSL_BN_ASM_GF2m -DSHA1_ASM -DSHA256_ASM -DSHA512_ASM -DMD5_ASM -DAES_ASM -DVPAES_ASM -DBSAES_ASM -DWHIRLPOOL_ASM -DGHASH_ASM Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: WARNING: tls [tls_init.c:611]: init_tls_h(): tls: 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 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [cfg/cfg_ctx.c:613]: cfg_set_now(): INFO: cfg_set_now(): tls.low_mem_threshold1 has been changed to 5242880 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [cfg/cfg_ctx.c:613]: cfg_set_now(): INFO: cfg_set_now(): tls.low_mem_threshold2 has been changed to 2621440 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:176]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is initially 124928 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:227]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is finally 249856 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:176]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is initially 124928 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [udp_server.c:227]: probe_max_receive_buffer(): INFO: udp_init: SO_RCVBUF is finally 249856 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:275]: fill_missing(): TLSs<default>: tls_method=9 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:287]: fill_missing(): TLSs<default>: certificate='/path/ssl/fooserver1.uio.no.crt' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:294]: fill_missing(): TLSs<default>: ca_list='/voip/packages/mgmt/ssl/terena_chain2.pem' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:301]: fill_missing(): TLSs<default>: crl='(null)' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:305]: fill_missing(): TLSs<default>: require_certificate=0 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:312]: fill_missing(): TLSs<default>: cipher_list='(null)' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:319]: fill_missing(): TLSs<default>: private_key='/path/ssl/fooserver1.uio.no.key' Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:323]: fill_missing(): TLSs<default>: verify_certificate=0 Dec 15 13:50:19 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:326]: fill_missing(): TLSs<default>: verify_depth=9 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:670]: set_verification(): TLSs<default>: No client certificate required and no checks performed Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:275]: fill_missing(): TLSc<default>: tls_method=9 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:287]: fill_missing(): TLSc<default>: certificate='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:294]: fill_missing(): TLSc<default>: ca_list='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:301]: fill_missing(): TLSc<default>: crl='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:305]: fill_missing(): TLSc<default>: require_certificate=0 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:312]: fill_missing(): TLSc<default>: cipher_list='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:319]: fill_missing(): TLSc<default>: private_key='(null)' Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:323]: fill_missing(): TLSc<default>: verify_certificate=0 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:326]: fill_missing(): TLSc<default>: verify_depth=9 Dec 15 13:50:23 fooserver1 /usr/sbin/kamailio[12118]: INFO: tls [tls_domain.c:673]: set_verification(): TLSc<default>: Server MAY present invalid certificate Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: db_postgres [km_pg_con.c:82]: db_postgres_new_connection(): SSL SYSCALL error: Resource temporarily unavailable#012FATAL: no pg_hba.conf entry for host "129.240.1.1", user "foo_test_user", database " foo_test", SSL off#012 Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: db_postgres [km_pg_con.c:95]: db_postgres_new_connection(): cleaning up 0x7fce98be0c78=pkg_free() Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [db.c:322]: db_do_init2(): could not add connection to the pool Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: sqlops [sql_api.c:166]: sql_connect(): failed to connect to the database [data] Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [sr_module.c:927]: init_mod_child(): init_mod_child(): Error while initializing module sqlops (/usr/lib64/kamailio/modules/sqlops.so) Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [pt.c:490]: fork_tcp_process(): ERROR: fork_tcp_process(): init_child failed for process 7, pid 12125, "tcp receiver (generic) child=0" Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12125]: ERROR: <core> [tcp_main.c:4962]: tcp_init_children(): ERROR: tcp_main: fork failed: Success Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12118]: ALERT: <core> [main.c:774]: handle_sigs(): child process 12125 exited normally, status=255 Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12118]: INFO: <core> [main.c:792]: handle_sigs(): INFO: terminating due to SIGCHLD Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12126]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12124]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12123]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12122]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12121]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12120]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received Dec 15 13:50:26 fooserver1 /usr/sbin/kamailio[12127]: INFO: <core> [main.c:843]: sig_usr(): INFO: signal 15 received
Any ideas?
Best regards, Øyvind
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
On 16.12.2014 10:44, Daniel-Constantin Mierla wrote:
The question would be more specific to the error message printed from postgres client library:
FATAL: no pg_hba.conf entry for host "129.240.1.1", user "foo_test_user", database " foo_test", SSL off
The issue here is why suddenly SSL when attempting to connect. When not loading the TLS module this does not happen. I've not been able to reorder any modules in order for it to succeed.
Is it something that is documented somewhere or maybe some web search can indicate the reasons why it happens?
Can you try loading tls module before db_postgres?
One thing which works sometimes is to increase the debuglevel to 5 and also set memdbg=5 and memlog=5. The massive logging causes extra startup delay. Maybe a TLS settings race? Non threadsafe interaction with libssl?
Øyvind
On 16/12/14 11:38, Øyvind Kolbu wrote:
On 16.12.2014 10:44, Daniel-Constantin Mierla wrote:
The question would be more specific to the error message printed from postgres client library:
FATAL: no pg_hba.conf entry for host "129.240.1.1", user "foo_test_user", database " foo_test", SSL off
The issue here is why suddenly SSL when attempting to connect. When not loading the TLS module this does not happen. I've not been able to reorder any modules in order for it to succeed.
Is it something that is documented somewhere or maybe some web search can indicate the reasons why it happens?
Can you try loading tls module before db_postgres?
One thing which works sometimes is to increase the debuglevel to 5 and also set memdbg=5 and memlog=5. The massive logging causes extra startup delay. Maybe a TLS settings race? Non threadsafe interaction with libssl?
TLS module initializes libssl when it is loaded. db_postgress creates connections at mod init, so it is later and inside same process (no fork at that moment).
Based on the new details, I understand that some connections succeed, some not, and even sometimes all connection succeed (when having lot of log messages that add delay). What is the operating system you have? Is selinux enabled? You can try to play with fork_delay and modinit_delay core parameters:
- http://www.kamailio.org/wiki/cookbooks/4.2.x/core#fork_delay
Cheers, Daniel
On 16.12.2014 11:51, Daniel-Constantin Mierla wrote:
TLS module initializes libssl when it is loaded. db_postgress creates connections at mod init, so it is later and inside same process (no fork at that moment).
Based on the new details, I understand that some connections succeed, some not, and even sometimes all connection succeed (when having lot of log messages that add delay). What is the operating system you have? Is selinux enabled? You can try to play with fork_delay and modinit_delay core parameters:
Tried both fork_delay and modinit_delay, nothing changed. The OS in RHEL6.6 with selinux enabled, which is mandatory for us to use.
Don't think fork limit is an issue, because tried children=40 without tls and that was no problem. children=2 with TLS failed as usual. children=40 with TLS created a core dump...
/usr/sbin/kamailio[23252]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f9cbcfff030), called from tls: tls_init.c: ser_free(291), first free tls: tls_init.c: ser_free(291) - aborting (gdb) bt #0 0x0000003feea32625 in raise () from /lib64/libc.so.6 #1 0x0000003feea33e05 in abort () from /lib64/libc.so.6 #2 0x0000000000548e74 in qm_free (qm=0x7f9cbbe30000, p=0x7f9cbcfff030, file=0x7f9cc027ea50 "tls: tls_init.c", func=0x7f9cc0280153 "ser_free", line=291) at mem/q_malloc.c:470 #3 0x00007f9cc025d33d in ser_free (ptr=0x7f9cbcfff030) at tls_init.c:291 #4 0x000000349a66ad1d in CRYPTO_free () from /usr/lib64/libcrypto.so.10 #5 0x000000349a6e88b1 in ERR_clear_error () from /usr/lib64/libcrypto.so.10 #6 0x000000349a739099 in CONF_modules_load () from /usr/lib64/libcrypto.so.10 #7 0x000000349a739147 in CONF_modules_load_file () from /usr/lib64/libcrypto.so.10 #8 0x000000349a73922e in OPENSSL_config () from /usr/lib64/libcrypto.so.10 #9 0x0000003e4a81a457 in ?? () from /usr/lib64/libpq.so.5 #10 0x0000003e4a80c5db in PQconnectPoll () from /usr/lib64/libpq.so.5 #11 0x0000003e4a80c8ee in ?? () from /usr/lib64/libpq.so.5 #12 0x0000003e4a80d574 in PQsetdbLogin () from /usr/lib64/libpq.so.5 #13 0x00007f9cc06c1603 in db_postgres_new_connection (id=0x7f9cc1cbba28) at km_pg_con.c:77 #14 0x00007f9cc08e1eaa in db_do_init2 (url=0x7f9cc1cb3178, new_connection=0x7f9cc06c0bb7 <db_postgres_new_connection>, pooling=DB_POOLING_PERMITTED) at db.c:320 #15 0x00007f9cc08e16d5 in db_do_init (url=0x7f9cc1cb3178, new_connection=0x7f9cc06c0bb7 <db_postgres_new_connection>) at db.c:273 #16 0x00007f9cc06bab2c in db_postgres_init (_url=0x7f9cc1cb3178) at km_dbase.c:133 #17 0x00007f9cc0afaee8 in sql_connect () at sql_api.c:162 #18 0x00007f9cc0b035ae in child_init (rank=40) at sqlops.c:145 #19 0x00000000004f854a in init_mod_child (m=0x7f9cc1cafa78, rank=40) at sr_module.c:924 #20 0x00000000004f83ed in init_mod_child (m=0x7f9cc1cb00a0, rank=40) at sr_module.c:921 #21 0x00000000004f83ed in init_mod_child (m=0x7f9cc1cb0780, rank=40) at sr_module.c:921 #22 0x00000000004f86d0 in init_child (rank=40) at sr_module.c:948 #23 0x0000000000491c5f in fork_process (child_id=40, desc=0x7fff94773ab0 "udp receiver child=39 sock=127.0.0.1:5060", make_sock=1) at pt.c:343 #24 0x000000000046d470 in main_loop () at main.c:1609 #25 0x00000000004706a7 in main (argc=21, argv=0x7fff94773d18) at main.c:2547
Need anything else from the core?
Øyvind
On 16/12/14 12:12, Øyvind Kolbu wrote:
On 16.12.2014 11:51, Daniel-Constantin Mierla wrote:
TLS module initializes libssl when it is loaded. db_postgress creates connections at mod init, so it is later and inside same process (no fork at that moment).
Based on the new details, I understand that some connections succeed, some not, and even sometimes all connection succeed (when having lot of log messages that add delay). What is the operating system you have? Is selinux enabled? You can try to play with fork_delay and modinit_delay core parameters:
Tried both fork_delay and modinit_delay, nothing changed. The OS in RHEL6.6 with selinux enabled, which is mandatory for us to use.
Don't think fork limit is an issue, because tried children=40 without tls and that was no problem. children=2 with TLS failed as usual. children=40 with TLS created a core dump...
Those parameters are not about number of children, but how fast to do some operations. I had troubles with selinux, because it has some obscure limits on how fast new connections can be opened. TLS is using quite some memory, I wonder if selinux have a limit on how fast one process keeps allocating... Have you tried with children=1?
/usr/sbin/kamailio[23252]: : <core> [mem/q_malloc.c:468]: qm_free(): BUG: qm_free: freeing already freed pointer (0x7f9cbcfff030), called from tls: tls_init.c: ser_free(291), first free tls: tls_init.c: ser_free(291) - aborting (gdb) bt #0 0x0000003feea32625 in raise () from /lib64/libc.so.6 #1 0x0000003feea33e05 in abort () from /lib64/libc.so.6 #2 0x0000000000548e74 in qm_free (qm=0x7f9cbbe30000, p=0x7f9cbcfff030, file=0x7f9cc027ea50 "tls: tls_init.c", func=0x7f9cc0280153 "ser_free", line=291) at mem/q_malloc.c:470 #3 0x00007f9cc025d33d in ser_free (ptr=0x7f9cbcfff030) at tls_init.c:291 #4 0x000000349a66ad1d in CRYPTO_free () from /usr/lib64/libcrypto.so.10 #5 0x000000349a6e88b1 in ERR_clear_error () from /usr/lib64/libcrypto.so.10 #6 0x000000349a739099 in CONF_modules_load () from /usr/lib64/libcrypto.so.10 #7 0x000000349a739147 in CONF_modules_load_file () from /usr/lib64/libcrypto.so.10 #8 0x000000349a73922e in OPENSSL_config () from /usr/lib64/libcrypto.so.10 #9 0x0000003e4a81a457 in ?? () from /usr/lib64/libpq.so.5 #10 0x0000003e4a80c5db in PQconnectPoll () from /usr/lib64/libpq.so.5 #11 0x0000003e4a80c8ee in ?? () from /usr/lib64/libpq.so.5 #12 0x0000003e4a80d574 in PQsetdbLogin () from /usr/lib64/libpq.so.5 #13 0x00007f9cc06c1603 in db_postgres_new_connection (id=0x7f9cc1cbba28) at km_pg_con.c:77 #14 0x00007f9cc08e1eaa in db_do_init2 (url=0x7f9cc1cb3178, new_connection=0x7f9cc06c0bb7 <db_postgres_new_connection>, pooling=DB_POOLING_PERMITTED) at db.c:320 #15 0x00007f9cc08e16d5 in db_do_init (url=0x7f9cc1cb3178, new_connection=0x7f9cc06c0bb7 <db_postgres_new_connection>) at db.c:273 #16 0x00007f9cc06bab2c in db_postgres_init (_url=0x7f9cc1cb3178) at km_dbase.c:133 #17 0x00007f9cc0afaee8 in sql_connect () at sql_api.c:162 #18 0x00007f9cc0b035ae in child_init (rank=40) at sqlops.c:145 #19 0x00000000004f854a in init_mod_child (m=0x7f9cc1cafa78, rank=40) at sr_module.c:924 #20 0x00000000004f83ed in init_mod_child (m=0x7f9cc1cb00a0, rank=40) at sr_module.c:921 #21 0x00000000004f83ed in init_mod_child (m=0x7f9cc1cb0780, rank=40) at sr_module.c:921 #22 0x00000000004f86d0 in init_child (rank=40) at sr_module.c:948 #23 0x0000000000491c5f in fork_process (child_id=40, desc=0x7fff94773ab0 "udp receiver child=39 sock=127.0.0.1:5060", make_sock=1) at pt.c:343 #24 0x000000000046d470 in main_loop () at main.c:1609 #25 0x00000000004706a7 in main (argc=21, argv=0x7fff94773d18) at main.c:2547
Need anything else from the core?
It looks like a double free done inside libssl, it cannot be controlled by us, you can set mem_safety=1
Cheers, Daniel
On 16.12.2014 12:23, Daniel-Constantin Mierla wrote:
Those parameters are not about number of children, but how fast to do some operations. I had troubles with selinux, because it has some obscure limits on how fast new connections can be opened. TLS is using quite some memory, I wonder if selinux have a limit on how fast one process keeps allocating... Have you tried with children=1?
Tried now with:
fork_delay=50000 modinit_delay=100000 mem_safety=1 fork=yes children=1
Now the usual error on start, but no crash.
Also tried disabling selinux. Did not help.
Øyvind
On 16/12/14 12:43, Øyvind Kolbu wrote:
On 16.12.2014 12:23, Daniel-Constantin Mierla wrote:
Those parameters are not about number of children, but how fast to do some operations. I had troubles with selinux, because it has some obscure limits on how fast new connections can be opened. TLS is using quite some memory, I wonder if selinux have a limit on how fast one process keeps allocating... Have you tried with children=1?
Tried now with:
fork_delay=50000 modinit_delay=100000 mem_safety=1 fork=yes children=1
Now the usual error on start, but no crash.
Also tried disabling selinux. Did not help.
Then, to clarify properly, have you ever got it started with higher debug level and memory operations printed to syslog?
Daniel
"DM" == Daniel-Constantin Mierla miconda@gmail.com writes:
DM> The question would be more specific to the error message printed from DM> postgres client library:
DM> FATAL: no pg_hba.conf entry for host "129.240.1.1", user DM> "foo_test_user", database " foo_test", SSL off
DM> Is it something that is documented somewhere or maybe some web search DM> can indicate the reasons why it happens?
His initial post mentioned that they require ssl for the pg tcp sockets; the error about pg_hba just confirms that.
-JimC
On 18/12/14 22:09, James Cloos wrote:
"DM" == Daniel-Constantin Mierla miconda@gmail.com writes:
DM> The question would be more specific to the error message printed from DM> postgres client library:
DM> FATAL: no pg_hba.conf entry for host "129.240.1.1", user DM> "foo_test_user", database " foo_test", SSL off
DM> Is it something that is documented somewhere or maybe some web search DM> can indicate the reasons why it happens?
His initial post mentioned that they require ssl for the pg tcp sockets; the error about pg_hba just confirms that.
Can you elaborate? Otherwise I don't see what's the role of this reply, because that was clear they want want tls for postgres.
The error message says 'no pg_hba.conf entry for host "..."' -- sounds like something missing in postgres client/server configuration.
Daniel
"DM" == Daniel-Constantin Mierla miconda@gmail.com writes:
DM> Can you elaborate? Otherwise I don't see what's the role of this reply, DM> because that was clear they want want tls for postgres.
Apologies that I wasn't clear.
DM> The error message says 'no pg_hba.conf entry for host "..."' -- sounds DM> like something missing in postgres client/server configuration.
It is. The important part is the no_ssl part; that just confirms what the poster wrote in his first message, that they limit connections to their pg to require ssl when connecting via tcp from host 129.240.1.1 as foo_test_user.
There is one issue I didn't spot at first, though. In the db name section of the error:
FATAL: no pg_hba.conf entry for host "129.240.1.1", user "foo_test_user", database " foo_test", SSL off
there is an extra space, " foo_test" vs "foo_test".
That might turn out to be the entire issue.
-JimC
On 19.12.2014 19:17, James Cloos wrote:
FATAL: no pg_hba.conf entry for host "129.240.1.1", user "foo_test_user", database " foo_test", SSL off
there is an extra space, " foo_test" vs "foo_test".
That might turn out to be the entire issue.
Sorry for the late reply, been gone on vacation.
The extra space in my redacted log is not the issue. The issue is that somehow when I enable the tls module in Kamailio, I can not connect to my postgres server anymore. Our server requires SSL, and the error message is returned from the server as a result of Kamailio not connecting with or attempting SSL anymore for db_postgres.
On 06/01/15 10:19, Øyvind Kolbu wrote:
On 19.12.2014 19:17, James Cloos wrote:
FATAL: no pg_hba.conf entry for host "129.240.1.1", user "foo_test_user", database " foo_test", SSL off
there is an extra space, " foo_test" vs "foo_test".
That might turn out to be the entire issue.
Sorry for the late reply, been gone on vacation.
The extra space in my redacted log is not the issue. The issue is that somehow when I enable the tls module in Kamailio, I can not connect to my postgres server anymore. Our server requires SSL, and the error message is returned from the server as a result of Kamailio not connecting with or attempting SSL anymore for db_postgres.
Searching on google about libpq and tls I found the notes about SSL Initialization at:
- http://www.postgresql.org/docs/9.3/static/libpq-ssl.html
Scroll down the page.
Can you try adding:
PQinitSSL(0);
inside function:
struct pg_con* db_postgres_new_connection(struct db_id* id)
in file:
modules/db_postgres/km_pg_con.c
Before line with:
ptr->con = PQsetdbLogin(id->host, ports, ...
If works, we have to make that optional via modparam or try auto-detect if ssl is initialized (finding tls is loaded, but some other modules can do it, even when tls is not initialized, so mod param could be a safe way).
Cheers, Daniel
On 07.01.2015 11:49, Daniel-Constantin Mierla wrote:
Searching on google about libpq and tls I found the notes about SSL Initialization at:
Scroll down the page.
Can you try adding:
PQinitSSL(0);
inside function:
struct pg_con* db_postgres_new_connection(struct db_id* id)
in file:
modules/db_postgres/km_pg_con.c
Before line with:
ptr->con = PQsetdbLogin(id->host, ports, ...
If works, we have to make that optional via modparam or try auto-detect if ssl is initialized (finding tls is loaded, but some other modules can do it, even when tls is not initialized, so mod param could be a safe way).
Thanks, just rebuilt git 2f690887b45dbc4, ~4.1.6.
Without tls enabled db_postgres fails with ERROR: db_postgres [km_pg_con.c:82]: db_postgres_new_connection(): could not create SSL context: SSL error code 336236705#012 ERROR: db_postgres [km_pg_con.c:95]: db_postgres_new_connection(): cleaning up 0x7f1cfe8ba3c0=pkg_free()
When attempting to start with tls enabled I get: INFO: tls [tls_mod.c:346]: mod_init(): With ECDH-Support! INFO: tls [tls_mod.c:349]: mod_init(): With Diffie Hellman ERROR: db_postgres [km_pg_con.c:82]: db_postgres_new_connection(): could not create SSL context: SSL error code 336236705#012 ERROR: db_postgres [km_pg_con.c:95]: db_postgres_new_connection(): cleaning up 0x7f10849d4310=pkg_free()
On 07/01/15 13:32, Øyvind Kolbu wrote:
On 07.01.2015 11:49, Daniel-Constantin Mierla wrote:
Searching on google about libpq and tls I found the notes about SSL Initialization at:
Scroll down the page.
Can you try adding:
PQinitSSL(0);
inside function:
struct pg_con* db_postgres_new_connection(struct db_id* id)
in file:
modules/db_postgres/km_pg_con.c
Before line with:
ptr->con = PQsetdbLogin(id->host, ports, ...
If works, we have to make that optional via modparam or try auto-detect if ssl is initialized (finding tls is loaded, but some other modules can do it, even when tls is not initialized, so mod param could be a safe way).
Thanks, just rebuilt git 2f690887b45dbc4, ~4.1.6.
Without tls enabled db_postgres fails with ERROR: db_postgres [km_pg_con.c:82]: db_postgres_new_connection(): could not create SSL context: SSL error code 336236705#012 ERROR: db_postgres [km_pg_con.c:95]: db_postgres_new_connection(): cleaning up 0x7f1cfe8ba3c0=pkg_free()
The workaround is only for the case when tls module is loaded. I said it needs tuning afterwards, if proved to work with tls module, to skip it otherwise.
When attempting to start with tls enabled I get: INFO: tls [tls_mod.c:346]: mod_init(): With ECDH-Support! INFO: tls [tls_mod.c:349]: mod_init(): With Diffie Hellman ERROR: db_postgres [km_pg_con.c:82]: db_postgres_new_connection(): could not create SSL context: SSL error code 336236705#012 ERROR: db_postgres [km_pg_con.c:95]: db_postgres_new_connection(): cleaning up 0x7f10849d4310=pkg_free()
So it complains that the ssl lib is not initialized completely.
Can you try the following:
- edit modules/tls/tls_init.c and add at the beginning of function 'int init_tls_h(void)':
if(tls_mod_initialized > 0) return 0;
- in modules/db_postgres/km_pg_con.c, add:
#include "../../tls_hooks_init.h"
- then in same file, before the line you added with PQinitSSL(0); add:
init_tls();
Recompile, reinstall, restart and test only with tls module loaded before the db_postgres.
Let's see the results and then I will make a proper patch if works.
Cheers, Daniel
On 07.01.2015 14:27, Daniel-Constantin Mierla wrote:
So it complains that the ssl lib is not initialized completely.
Can you try the following:
- edit modules/tls/tls_init.c and add at the beginning of function 'int
init_tls_h(void)':
if(tls_mod_initialized > 0) return 0;
- in modules/db_postgres/km_pg_con.c, add:
#include "../../tls_hooks_init.h"
- then in same file, before the line you added with PQinitSSL(0); add:
init_tls();
Recompile, reinstall, restart and test only with tls module loaded before the db_postgres.
Let's see the results and then I will make a proper patch if works.
Crashed again, this time with core dump. Used the following patch: --- modules/db_postgres/km_pg_con.c.orig 2015-01-09 15:39:02.411067822 +0100 +++ modules/db_postgres/km_pg_con.c 2015-01-09 15:40:32.980577115 +0100 @@ -29,6 +29,7 @@ #include "../../mem/mem.h" #include "../../dprint.h" #include "../../ut.h" +#include "../../tls_hooks_init.h" #include <string.h> #include <time.h>
@@ -74,6 +75,9 @@ ZSW(id->database)); }
+ init_tls(); + PQinitSSL(0); + ptr->con = PQsetdbLogin(id->host, ports, NULL, NULL, id->database, id->username, id->password); LM_DBG("PQsetdbLogin(%p)\n", ptr->con);
--- modules/tls/tls_init.c.orig 2015-01-09 15:37:16.268298551 +0100 +++ modules/tls/tls_init.c 2015-01-09 15:38:31.924559696 +0100 @@ -498,6 +498,8 @@ str s; cfg_ctx_t* cfg_ctx;
+ if(tls_mod_initialized > 0) return 0; + #if OPENSSL_VERSION_NUMBER < 0x00907000L WARN("You are using an old version of OpenSSL (< 0.9.7). Upgrade!\n"); #endif
And got this message: /usr/sbin/kamailio[22789]: INFO: tls [tls_mod.c:346]: mod_init(): With ECDH-Support! /usr/sbin/kamailio[22789]: INFO: tls [tls_mod.c:349]: mod_init(): With Diffie Hellman /usr/sbin/kamailio[22789]: INFO: ldap [ldap_mod.c:246]: mod_init(): OpenLDAP - 20439 /usr/sbin/kamailio[22789]: INFO: rr [../outbound/api.h:54]: ob_load_api(): Failed to import bind_ob /usr/sbin/kamailio[22789]: INFO: rr [rr_mod.c:159]: mod_init(): outbound module not available /usr/sbin/kamailio[22789]: INFO: usrloc [hslot.c:53]: ul_init_locks(): locks array size 512 /usr/sbin/kamailio[22789]: INFO: tls [tls_init.c:551]: init_tls_h(): tls: _init_tls_h: compiled with openssl version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, compression: on [...] /usr/sbin/kamailio[22789]: : <core> [pt.c:164]: get_max_procs(): BUG: get_max_procs() called too early (it must _not_ be called from mod_init())
and the following backtrace: #0 0x0000003196e32625 in raise () from /lib64/libc.so.6 #1 0x0000003196e33e05 in abort () from /lib64/libc.so.6 #2 0x000000000049138f in get_max_procs () at pt.c:165 #3 0x00007f8ca8655106 in init_tls_h () at tls_init.c:598 #4 0x00000000005372b9 in init_tls () at tls_hooks.c:70 #5 0x00007f8c9fffb655 in db_postgres_new_connection (id=0x7f8ca8d7d0b0) at km_pg_con.c:78 #6 0x00007f8c9fbd0eaa in db_do_init2 (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>, pooling=DB_POOLING_PERMITTED) at db.c:320 #7 0x00007f8c9fbd06d5 in db_do_init (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>) at db.c:273 #8 0x00007f8c9fff4bbc in db_postgres_init (_url=0x7f8c9ca52cd0) at km_dbase.c:133 #9 0x00007f8c9c81429f in dlg_connect_db (db_url=0x7f8c9ca52cd0) at dlg_db_handler.c:132 #10 0x00007f8c9c814457 in init_dlg_db (db_url=0x7f8c9ca52cd0, dlg_hash_size=4096, db_update_period=60, fetch_num_rows=200) at dlg_db_handler.c:146 #11 0x00007f8c9c80c7cd in mod_init () at dialog.c:700 #12 0x00000000004f884d in init_mod (m=0x7f8ca88e82d8) at sr_module.c:967 #13 0x00000000004f8703 in init_mod (m=0x7f8ca88e8f98) at sr_module.c:964 #14 0x00000000004f8703 in init_mod (m=0x7f8ca88e94c0) at sr_module.c:964
(gdb) bt full #0 0x0000003196e32625 in raise () from /lib64/libc.so.6 No symbol table info available. #1 0x0000003196e33e05 in abort () from /lib64/libc.so.6 No symbol table info available. #2 0x000000000049138f in get_max_procs () at pt.c:165 __FUNCTION__ = "get_max_procs" #3 0x00007f8ca8655106 in init_tls_h () at tls_init.c:598 ssl_version = 268439647 lib_kerberos = 1 lib_zlib = 1 kerberos_support = 1 comp_support = 1 lib_cflags = 0x319a1dede0 "compiler: gcc -fPIC -DOPENSSL_PIC -DZLIB -DOPENSSL_THREADS -D_REENTRANT -DDSO_DLFCN -DHAVE_DLFCN_H -DKRB5_MIT -m64 -DL_ENDIAN -DTERMIO -Wall -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fs"... low_mem_threshold1 = -1 low_mem_threshold2 = -1 tls_grp = {s = 0x7fffcec76560 "\025", len = 0} s = {s = 0x7f8ca0010660 "db_postgres_new_connection", len = -1462250968} cfg_ctx = 0x7f8ca0010378 __FUNCTION__ = "init_tls_h" #4 0x00000000005372b9 in init_tls () at tls_hooks.c:70
#5 0x00007f8c9fffb655 in db_postgres_new_connection (id=0x7f8ca8d7d0b0) at km_pg_con.c:78 ptr = 0x7f8ca8d7d310 ports = 0x0 __FUNCTION__ = "db_postgres_new_connection" #6 0x00007f8c9fbd0eaa in db_do_init2 (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>, pooling=DB_POOLING_PERMITTED) at db.c:320 id = 0x7f8ca8d7d0b0 con = 0x0 res = 0x7f8ca8d7d008 con_size = 24 __FUNCTION__ = "db_do_init2" #7 0x00007f8c9fbd06d5 in db_do_init (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>) at db.c:273 No locals. #8 0x00007f8c9fff4bbc in db_postgres_init (_url=0x7f8c9ca52cd0) at km_dbase.c:133 No locals. #9 0x00007f8c9c81429f in dlg_connect_db (db_url=0x7f8c9ca52cd0) at dlg_db_handler.c:132 __FUNCTION__ = "dlg_connect_db"
Kept the core in case you need it.
Do you have a testbed server where I can login and try couple of patches? It might be faster to try to get it solved this way ... Or maybe someone can make one server available with postgress and you configure it there in a similar way -- I am not a postgres user and no resourse to setup something new at this moment.
If not, I will try to give some other steps to try to fix it this way, just is going to be probably slow ...
Daniel
On 09/01/15 16:02, Øyvind Kolbu wrote:
On 07.01.2015 14:27, Daniel-Constantin Mierla wrote:
So it complains that the ssl lib is not initialized completely.
Can you try the following:
- edit modules/tls/tls_init.c and add at the beginning of function 'int
init_tls_h(void)':
if(tls_mod_initialized > 0) return 0;
- in modules/db_postgres/km_pg_con.c, add:
#include "../../tls_hooks_init.h"
- then in same file, before the line you added with PQinitSSL(0); add:
init_tls();
Recompile, reinstall, restart and test only with tls module loaded before the db_postgres.
Let's see the results and then I will make a proper patch if works.
Crashed again, this time with core dump. Used the following patch: --- modules/db_postgres/km_pg_con.c.orig 2015-01-09 15:39:02.411067822 +0100 +++ modules/db_postgres/km_pg_con.c 2015-01-09 15:40:32.980577115 +0100 @@ -29,6 +29,7 @@ #include "../../mem/mem.h" #include "../../dprint.h" #include "../../ut.h" +#include "../../tls_hooks_init.h" #include <string.h> #include <time.h>
@@ -74,6 +75,9 @@ ZSW(id->database)); }
init_tls();PQinitSSL(0);ptr->con = PQsetdbLogin(id->host, ports, NULL, NULL,id->database, id->username, id->password); LM_DBG("PQsetdbLogin(%p)\n", ptr->con);
--- modules/tls/tls_init.c.orig 2015-01-09 15:37:16.268298551 +0100 +++ modules/tls/tls_init.c 2015-01-09 15:38:31.924559696 +0100 @@ -498,6 +498,8 @@ str s; cfg_ctx_t* cfg_ctx;
if(tls_mod_initialized > 0) return 0;#if OPENSSL_VERSION_NUMBER < 0x00907000L WARN("You are using an old version of OpenSSL (< 0.9.7). Upgrade!\n"); #endif
And got this message: /usr/sbin/kamailio[22789]: INFO: tls [tls_mod.c:346]: mod_init(): With ECDH-Support! /usr/sbin/kamailio[22789]: INFO: tls [tls_mod.c:349]: mod_init(): With Diffie Hellman /usr/sbin/kamailio[22789]: INFO: ldap [ldap_mod.c:246]: mod_init(): OpenLDAP - 20439 /usr/sbin/kamailio[22789]: INFO: rr [../outbound/api.h:54]: ob_load_api(): Failed to import bind_ob /usr/sbin/kamailio[22789]: INFO: rr [rr_mod.c:159]: mod_init(): outbound module not available /usr/sbin/kamailio[22789]: INFO: usrloc [hslot.c:53]: ul_init_locks(): locks array size 512 /usr/sbin/kamailio[22789]: INFO: tls [tls_init.c:551]: init_tls_h(): tls: _init_tls_h: compiled with openssl version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, compression: on [...] /usr/sbin/kamailio[22789]: : <core> [pt.c:164]: get_max_procs(): BUG: get_max_procs() called too early (it must _not_ be called from mod_init())
and the following backtrace: #0 0x0000003196e32625 in raise () from /lib64/libc.so.6 #1 0x0000003196e33e05 in abort () from /lib64/libc.so.6 #2 0x000000000049138f in get_max_procs () at pt.c:165 #3 0x00007f8ca8655106 in init_tls_h () at tls_init.c:598 #4 0x00000000005372b9 in init_tls () at tls_hooks.c:70 #5 0x00007f8c9fffb655 in db_postgres_new_connection (id=0x7f8ca8d7d0b0) at km_pg_con.c:78 #6 0x00007f8c9fbd0eaa in db_do_init2 (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>, pooling=DB_POOLING_PERMITTED) at db.c:320 #7 0x00007f8c9fbd06d5 in db_do_init (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>) at db.c:273 #8 0x00007f8c9fff4bbc in db_postgres_init (_url=0x7f8c9ca52cd0) at km_dbase.c:133 #9 0x00007f8c9c81429f in dlg_connect_db (db_url=0x7f8c9ca52cd0) at dlg_db_handler.c:132 #10 0x00007f8c9c814457 in init_dlg_db (db_url=0x7f8c9ca52cd0, dlg_hash_size=4096, db_update_period=60, fetch_num_rows=200) at dlg_db_handler.c:146 #11 0x00007f8c9c80c7cd in mod_init () at dialog.c:700 #12 0x00000000004f884d in init_mod (m=0x7f8ca88e82d8) at sr_module.c:967 #13 0x00000000004f8703 in init_mod (m=0x7f8ca88e8f98) at sr_module.c:964 #14 0x00000000004f8703 in init_mod (m=0x7f8ca88e94c0) at sr_module.c:964
(gdb) bt full #0 0x0000003196e32625 in raise () from /lib64/libc.so.6 No symbol table info available. #1 0x0000003196e33e05 in abort () from /lib64/libc.so.6 No symbol table info available. #2 0x000000000049138f in get_max_procs () at pt.c:165 __FUNCTION__ = "get_max_procs" #3 0x00007f8ca8655106 in init_tls_h () at tls_init.c:598 ssl_version = 268439647 lib_kerberos = 1 lib_zlib = 1 kerberos_support = 1 comp_support = 1 lib_cflags = 0x319a1dede0 "compiler: gcc -fPIC -DOPENSSL_PIC -DZLIB -DOPENSSL_THREADS -D_REENTRANT -DDSO_DLFCN -DHAVE_DLFCN_H -DKRB5_MIT -m64 -DL_ENDIAN -DTERMIO -Wall -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fs"... low_mem_threshold1 = -1 low_mem_threshold2 = -1 tls_grp = {s = 0x7fffcec76560 "\025", len = 0} s = {s = 0x7f8ca0010660 "db_postgres_new_connection", len = -1462250968} cfg_ctx = 0x7f8ca0010378 __FUNCTION__ = "init_tls_h" #4 0x00000000005372b9 in init_tls () at tls_hooks.c:70
#5 0x00007f8c9fffb655 in db_postgres_new_connection (id=0x7f8ca8d7d0b0) at km_pg_con.c:78 ptr = 0x7f8ca8d7d310 ports = 0x0 __FUNCTION__ = "db_postgres_new_connection" #6 0x00007f8c9fbd0eaa in db_do_init2 (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>, pooling=DB_POOLING_PERMITTED) at db.c:320 id = 0x7f8ca8d7d0b0 con = 0x0 res = 0x7f8ca8d7d008 con_size = 24 __FUNCTION__ = "db_do_init2" #7 0x00007f8c9fbd06d5 in db_do_init (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>) at db.c:273 No locals. #8 0x00007f8c9fff4bbc in db_postgres_init (_url=0x7f8c9ca52cd0) at km_dbase.c:133 No locals. #9 0x00007f8c9c81429f in dlg_connect_db (db_url=0x7f8c9ca52cd0) at dlg_db_handler.c:132 __FUNCTION__ = "dlg_connect_db"
Kept the core in case you need it.
To conclude this thread -- it was reported that the patches I did to break the initialization of libssl have solved the issue. Postgres module connects ok when tls module is loaded. Also, tls connections seems to work as expected. Patches are for now in master and 4.2 branches (backport to 4.1 also considered).
Cheers, Daniel
On 09/01/15 18:30, Daniel-Constantin Mierla wrote:
Do you have a testbed server where I can login and try couple of patches? It might be faster to try to get it solved this way ... Or maybe someone can make one server available with postgress and you configure it there in a similar way -- I am not a postgres user and no resourse to setup something new at this moment.
If not, I will try to give some other steps to try to fix it this way, just is going to be probably slow ...
Daniel
On 09/01/15 16:02, Øyvind Kolbu wrote:
On 07.01.2015 14:27, Daniel-Constantin Mierla wrote:
So it complains that the ssl lib is not initialized completely.
Can you try the following:
- edit modules/tls/tls_init.c and add at the beginning of function 'int
init_tls_h(void)':
if(tls_mod_initialized > 0) return 0;
- in modules/db_postgres/km_pg_con.c, add:
#include "../../tls_hooks_init.h"
- then in same file, before the line you added with PQinitSSL(0); add:
init_tls();
Recompile, reinstall, restart and test only with tls module loaded before the db_postgres.
Let's see the results and then I will make a proper patch if works.
Crashed again, this time with core dump. Used the following patch: --- modules/db_postgres/km_pg_con.c.orig 2015-01-09 15:39:02.411067822 +0100 +++ modules/db_postgres/km_pg_con.c 2015-01-09 15:40:32.980577115 +0100 @@ -29,6 +29,7 @@ #include "../../mem/mem.h" #include "../../dprint.h" #include "../../ut.h" +#include "../../tls_hooks_init.h" #include <string.h> #include <time.h>
@@ -74,6 +75,9 @@ ZSW(id->database)); }
init_tls();PQinitSSL(0);ptr->con = PQsetdbLogin(id->host, ports, NULL, NULL,id->database, id->username, id->password); LM_DBG("PQsetdbLogin(%p)\n", ptr->con);
--- modules/tls/tls_init.c.orig 2015-01-09 15:37:16.268298551 +0100 +++ modules/tls/tls_init.c 2015-01-09 15:38:31.924559696 +0100 @@ -498,6 +498,8 @@ str s; cfg_ctx_t* cfg_ctx;
if(tls_mod_initialized > 0) return 0;#if OPENSSL_VERSION_NUMBER < 0x00907000L WARN("You are using an old version of OpenSSL (< 0.9.7). Upgrade!\n"); #endif
And got this message: /usr/sbin/kamailio[22789]: INFO: tls [tls_mod.c:346]: mod_init(): With ECDH-Support! /usr/sbin/kamailio[22789]: INFO: tls [tls_mod.c:349]: mod_init(): With Diffie Hellman /usr/sbin/kamailio[22789]: INFO: ldap [ldap_mod.c:246]: mod_init(): OpenLDAP - 20439 /usr/sbin/kamailio[22789]: INFO: rr [../outbound/api.h:54]: ob_load_api(): Failed to import bind_ob /usr/sbin/kamailio[22789]: INFO: rr [rr_mod.c:159]: mod_init(): outbound module not available /usr/sbin/kamailio[22789]: INFO: usrloc [hslot.c:53]: ul_init_locks(): locks array size 512 /usr/sbin/kamailio[22789]: INFO: tls [tls_init.c:551]: init_tls_h(): tls: _init_tls_h: compiled with openssl version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, compression: on [...] /usr/sbin/kamailio[22789]: : <core> [pt.c:164]: get_max_procs(): BUG: get_max_procs() called too early (it must _not_ be called from mod_init())
and the following backtrace: #0 0x0000003196e32625 in raise () from /lib64/libc.so.6 #1 0x0000003196e33e05 in abort () from /lib64/libc.so.6 #2 0x000000000049138f in get_max_procs () at pt.c:165 #3 0x00007f8ca8655106 in init_tls_h () at tls_init.c:598 #4 0x00000000005372b9 in init_tls () at tls_hooks.c:70 #5 0x00007f8c9fffb655 in db_postgres_new_connection (id=0x7f8ca8d7d0b0) at km_pg_con.c:78 #6 0x00007f8c9fbd0eaa in db_do_init2 (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>, pooling=DB_POOLING_PERMITTED) at db.c:320 #7 0x00007f8c9fbd06d5 in db_do_init (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>) at db.c:273 #8 0x00007f8c9fff4bbc in db_postgres_init (_url=0x7f8c9ca52cd0) at km_dbase.c:133 #9 0x00007f8c9c81429f in dlg_connect_db (db_url=0x7f8c9ca52cd0) at dlg_db_handler.c:132 #10 0x00007f8c9c814457 in init_dlg_db (db_url=0x7f8c9ca52cd0, dlg_hash_size=4096, db_update_period=60, fetch_num_rows=200) at dlg_db_handler.c:146 #11 0x00007f8c9c80c7cd in mod_init () at dialog.c:700 #12 0x00000000004f884d in init_mod (m=0x7f8ca88e82d8) at sr_module.c:967 #13 0x00000000004f8703 in init_mod (m=0x7f8ca88e8f98) at sr_module.c:964 #14 0x00000000004f8703 in init_mod (m=0x7f8ca88e94c0) at sr_module.c:964
(gdb) bt full #0 0x0000003196e32625 in raise () from /lib64/libc.so.6 No symbol table info available. #1 0x0000003196e33e05 in abort () from /lib64/libc.so.6 No symbol table info available. #2 0x000000000049138f in get_max_procs () at pt.c:165 __FUNCTION__ = "get_max_procs" #3 0x00007f8ca8655106 in init_tls_h () at tls_init.c:598 ssl_version = 268439647 lib_kerberos = 1 lib_zlib = 1 kerberos_support = 1 comp_support = 1 lib_cflags = 0x319a1dede0 "compiler: gcc -fPIC -DOPENSSL_PIC -DZLIB -DOPENSSL_THREADS -D_REENTRANT -DDSO_DLFCN -DHAVE_DLFCN_H -DKRB5_MIT -m64 -DL_ENDIAN -DTERMIO -Wall -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fs"... low_mem_threshold1 = -1 low_mem_threshold2 = -1 tls_grp = {s = 0x7fffcec76560 "\025", len = 0} s = {s = 0x7f8ca0010660 "db_postgres_new_connection", len = -1462250968} cfg_ctx = 0x7f8ca0010378 __FUNCTION__ = "init_tls_h" #4 0x00000000005372b9 in init_tls () at tls_hooks.c:70
#5 0x00007f8c9fffb655 in db_postgres_new_connection (id=0x7f8ca8d7d0b0) at km_pg_con.c:78 ptr = 0x7f8ca8d7d310 ports = 0x0 __FUNCTION__ = "db_postgres_new_connection" #6 0x00007f8c9fbd0eaa in db_do_init2 (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>, pooling=DB_POOLING_PERMITTED) at db.c:320 id = 0x7f8ca8d7d0b0 con = 0x0 res = 0x7f8ca8d7d008 con_size = 24 __FUNCTION__ = "db_do_init2" #7 0x00007f8c9fbd06d5 in db_do_init (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>) at db.c:273 No locals. #8 0x00007f8c9fff4bbc in db_postgres_init (_url=0x7f8c9ca52cd0) at km_dbase.c:133 No locals. #9 0x00007f8c9c81429f in dlg_connect_db (db_url=0x7f8c9ca52cd0) at dlg_db_handler.c:132 __FUNCTION__ = "dlg_connect_db"
Kept the core in case you need it.
On 28 Jan 2015, at 13:57, Daniel-Constantin Mierla miconda@gmail.com wrote:
To conclude this thread -- it was reported that the patches I did to break the initialization of libssl have solved the issue. Postgres module connects ok when tls module is loaded. Also, tls connections seems to work as expected. Patches are for now in master and 4.2 branches (backport to 4.1 also considered).
Thank you for working on this!
/O
Cheers, Daniel
On 09/01/15 18:30, Daniel-Constantin Mierla wrote:
Do you have a testbed server where I can login and try couple of patches? It might be faster to try to get it solved this way ... Or maybe someone can make one server available with postgress and you configure it there in a similar way -- I am not a postgres user and no resourse to setup something new at this moment.
If not, I will try to give some other steps to try to fix it this way, just is going to be probably slow ...
Daniel
On 09/01/15 16:02, Øyvind Kolbu wrote:
On 07.01.2015 14:27, Daniel-Constantin Mierla wrote:
So it complains that the ssl lib is not initialized completely.
Can you try the following:
- edit modules/tls/tls_init.c and add at the beginning of function 'int
init_tls_h(void)':
if(tls_mod_initialized > 0) return 0;
- in modules/db_postgres/km_pg_con.c, add:
#include "../../tls_hooks_init.h"
- then in same file, before the line you added with PQinitSSL(0); add:
init_tls();
Recompile, reinstall, restart and test only with tls module loaded before the db_postgres.
Let's see the results and then I will make a proper patch if works.
Crashed again, this time with core dump. Used the following patch: --- modules/db_postgres/km_pg_con.c.orig 2015-01-09 15:39:02.411067822 +0100 +++ modules/db_postgres/km_pg_con.c 2015-01-09 15:40:32.980577115 +0100 @@ -29,6 +29,7 @@ #include "../../mem/mem.h" #include "../../dprint.h" #include "../../ut.h" +#include "../../tls_hooks_init.h" #include <string.h> #include <time.h>
@@ -74,6 +75,9 @@ ZSW(id->database)); }
init_tls();PQinitSSL(0);ptr->con = PQsetdbLogin(id->host, ports, NULL, NULL,id->database, id->username, id->password); LM_DBG("PQsetdbLogin(%p)\n", ptr->con);
--- modules/tls/tls_init.c.orig 2015-01-09 15:37:16.268298551 +0100 +++ modules/tls/tls_init.c 2015-01-09 15:38:31.924559696 +0100 @@ -498,6 +498,8 @@ str s; cfg_ctx_t* cfg_ctx;
if(tls_mod_initialized > 0) return 0;#if OPENSSL_VERSION_NUMBER < 0x00907000L WARN("You are using an old version of OpenSSL (< 0.9.7). Upgrade!\n"); #endif
And got this message: /usr/sbin/kamailio[22789]: INFO: tls [tls_mod.c:346]: mod_init(): With ECDH-Support! /usr/sbin/kamailio[22789]: INFO: tls [tls_mod.c:349]: mod_init(): With Diffie Hellman /usr/sbin/kamailio[22789]: INFO: ldap [ldap_mod.c:246]: mod_init(): OpenLDAP - 20439 /usr/sbin/kamailio[22789]: INFO: rr [../outbound/api.h:54]: ob_load_api(): Failed to import bind_ob /usr/sbin/kamailio[22789]: INFO: rr [rr_mod.c:159]: mod_init(): outbound module not available /usr/sbin/kamailio[22789]: INFO: usrloc [hslot.c:53]: ul_init_locks(): locks array size 512 /usr/sbin/kamailio[22789]: INFO: tls [tls_init.c:551]: init_tls_h(): tls: _init_tls_h: compiled with openssl version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, compression: on [...] /usr/sbin/kamailio[22789]: : <core> [pt.c:164]: get_max_procs(): BUG: get_max_procs() called too early (it must _not_ be called from mod_init())
and the following backtrace: #0 0x0000003196e32625 in raise () from /lib64/libc.so.6 #1 0x0000003196e33e05 in abort () from /lib64/libc.so.6 #2 0x000000000049138f in get_max_procs () at pt.c:165 #3 0x00007f8ca8655106 in init_tls_h () at tls_init.c:598 #4 0x00000000005372b9 in init_tls () at tls_hooks.c:70 #5 0x00007f8c9fffb655 in db_postgres_new_connection (id=0x7f8ca8d7d0b0) at km_pg_con.c:78 #6 0x00007f8c9fbd0eaa in db_do_init2 (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>, pooling=DB_POOLING_PERMITTED) at db.c:320 #7 0x00007f8c9fbd06d5 in db_do_init (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>) at db.c:273 #8 0x00007f8c9fff4bbc in db_postgres_init (_url=0x7f8c9ca52cd0) at km_dbase.c:133 #9 0x00007f8c9c81429f in dlg_connect_db (db_url=0x7f8c9ca52cd0) at dlg_db_handler.c:132 #10 0x00007f8c9c814457 in init_dlg_db (db_url=0x7f8c9ca52cd0, dlg_hash_size=4096, db_update_period=60, fetch_num_rows=200) at dlg_db_handler.c:146 #11 0x00007f8c9c80c7cd in mod_init () at dialog.c:700 #12 0x00000000004f884d in init_mod (m=0x7f8ca88e82d8) at sr_module.c:967 #13 0x00000000004f8703 in init_mod (m=0x7f8ca88e8f98) at sr_module.c:964 #14 0x00000000004f8703 in init_mod (m=0x7f8ca88e94c0) at sr_module.c:964
(gdb) bt full #0 0x0000003196e32625 in raise () from /lib64/libc.so.6 No symbol table info available. #1 0x0000003196e33e05 in abort () from /lib64/libc.so.6 No symbol table info available. #2 0x000000000049138f in get_max_procs () at pt.c:165 __FUNCTION__ = "get_max_procs" #3 0x00007f8ca8655106 in init_tls_h () at tls_init.c:598 ssl_version = 268439647 lib_kerberos = 1 lib_zlib = 1 kerberos_support = 1 comp_support = 1 lib_cflags = 0x319a1dede0 "compiler: gcc -fPIC -DOPENSSL_PIC -DZLIB -DOPENSSL_THREADS -D_REENTRANT -DDSO_DLFCN -DHAVE_DLFCN_H -DKRB5_MIT -m64 -DL_ENDIAN -DTERMIO -Wall -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fs"... low_mem_threshold1 = -1 low_mem_threshold2 = -1 tls_grp = {s = 0x7fffcec76560 "\025", len = 0} s = {s = 0x7f8ca0010660 "db_postgres_new_connection", len = -1462250968} cfg_ctx = 0x7f8ca0010378 __FUNCTION__ = "init_tls_h" #4 0x00000000005372b9 in init_tls () at tls_hooks.c:70
#5 0x00007f8c9fffb655 in db_postgres_new_connection (id=0x7f8ca8d7d0b0) at km_pg_con.c:78 ptr = 0x7f8ca8d7d310 ports = 0x0 __FUNCTION__ = "db_postgres_new_connection" #6 0x00007f8c9fbd0eaa in db_do_init2 (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>, pooling=DB_POOLING_PERMITTED) at db.c:320 id = 0x7f8ca8d7d0b0 con = 0x0 res = 0x7f8ca8d7d008 con_size = 24 __FUNCTION__ = "db_do_init2" #7 0x00007f8c9fbd06d5 in db_do_init (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>) at db.c:273 No locals. #8 0x00007f8c9fff4bbc in db_postgres_init (_url=0x7f8c9ca52cd0) at km_dbase.c:133 No locals. #9 0x00007f8c9c81429f in dlg_connect_db (db_url=0x7f8c9ca52cd0) at dlg_db_handler.c:132 __FUNCTION__ = "dlg_connect_db"
Kept the core in case you need it.
-- Daniel-Constantin Mierla http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list sr-users@lists.sip-router.org http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
Great work, thank you!
Best regards, Øyvind
Den 28.01.2015 13:57, skrev Daniel-Constantin Mierla:
To conclude this thread -- it was reported that the patches I did to break the initialization of libssl have solved the issue. Postgres module connects ok when tls module is loaded. Also, tls connections seems to work as expected. Patches are for now in master and 4.2 branches (backport to 4.1 also considered).
Cheers, Daniel
On 09/01/15 18:30, Daniel-Constantin Mierla wrote:
Do you have a testbed server where I can login and try couple of patches? It might be faster to try to get it solved this way ... Or maybe someone can make one server available with postgress and you configure it there in a similar way -- I am not a postgres user and no resourse to setup something new at this moment.
If not, I will try to give some other steps to try to fix it this way, just is going to be probably slow ...
Daniel
On 09/01/15 16:02, Øyvind Kolbu wrote:
On 07.01.2015 14:27, Daniel-Constantin Mierla wrote:
So it complains that the ssl lib is not initialized completely.
Can you try the following:
- edit modules/tls/tls_init.c and add at the beginning of function 'int
init_tls_h(void)':
if(tls_mod_initialized > 0) return 0;
- in modules/db_postgres/km_pg_con.c, add:
#include "../../tls_hooks_init.h"
- then in same file, before the line you added with PQinitSSL(0); add:
init_tls();
Recompile, reinstall, restart and test only with tls module loaded before the db_postgres.
Let's see the results and then I will make a proper patch if works.
Crashed again, this time with core dump. Used the following patch: --- modules/db_postgres/km_pg_con.c.orig 2015-01-09 15:39:02.411067822 +0100 +++ modules/db_postgres/km_pg_con.c 2015-01-09 15:40:32.980577115 +0100 @@ -29,6 +29,7 @@ #include "../../mem/mem.h" #include "../../dprint.h" #include "../../ut.h" +#include "../../tls_hooks_init.h" #include <string.h> #include <time.h>
@@ -74,6 +75,9 @@ ZSW(id->database)); }
init_tls();PQinitSSL(0);ptr->con = PQsetdbLogin(id->host, ports, NULL, NULL,id->database, id->username, id->password); LM_DBG("PQsetdbLogin(%p)\n", ptr->con);
--- modules/tls/tls_init.c.orig 2015-01-09 15:37:16.268298551 +0100 +++ modules/tls/tls_init.c 2015-01-09 15:38:31.924559696 +0100 @@ -498,6 +498,8 @@ str s; cfg_ctx_t* cfg_ctx;
if(tls_mod_initialized > 0) return 0;- #if OPENSSL_VERSION_NUMBER < 0x00907000L WARN("You are using an old version of OpenSSL (< 0.9.7).
Upgrade!\n"); #endif
And got this message: /usr/sbin/kamailio[22789]: INFO: tls [tls_mod.c:346]: mod_init(): With ECDH-Support! /usr/sbin/kamailio[22789]: INFO: tls [tls_mod.c:349]: mod_init(): With Diffie Hellman /usr/sbin/kamailio[22789]: INFO: ldap [ldap_mod.c:246]: mod_init(): OpenLDAP - 20439 /usr/sbin/kamailio[22789]: INFO: rr [../outbound/api.h:54]: ob_load_api(): Failed to import bind_ob /usr/sbin/kamailio[22789]: INFO: rr [rr_mod.c:159]: mod_init(): outbound module not available /usr/sbin/kamailio[22789]: INFO: usrloc [hslot.c:53]: ul_init_locks(): locks array size 512 /usr/sbin/kamailio[22789]: INFO: tls [tls_init.c:551]: init_tls_h(): tls: _init_tls_h: compiled with openssl version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, compression: on [...] /usr/sbin/kamailio[22789]: : <core> [pt.c:164]: get_max_procs(): BUG: get_max_procs() called too early (it must _not_ be called from mod_init())
and the following backtrace: #0 0x0000003196e32625 in raise () from /lib64/libc.so.6 #1 0x0000003196e33e05 in abort () from /lib64/libc.so.6 #2 0x000000000049138f in get_max_procs () at pt.c:165 #3 0x00007f8ca8655106 in init_tls_h () at tls_init.c:598 #4 0x00000000005372b9 in init_tls () at tls_hooks.c:70 #5 0x00007f8c9fffb655 in db_postgres_new_connection (id=0x7f8ca8d7d0b0) at km_pg_con.c:78 #6 0x00007f8c9fbd0eaa in db_do_init2 (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>, pooling=DB_POOLING_PERMITTED) at db.c:320 #7 0x00007f8c9fbd06d5 in db_do_init (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>) at db.c:273 #8 0x00007f8c9fff4bbc in db_postgres_init (_url=0x7f8c9ca52cd0) at km_dbase.c:133 #9 0x00007f8c9c81429f in dlg_connect_db (db_url=0x7f8c9ca52cd0) at dlg_db_handler.c:132 #10 0x00007f8c9c814457 in init_dlg_db (db_url=0x7f8c9ca52cd0, dlg_hash_size=4096, db_update_period=60, fetch_num_rows=200) at dlg_db_handler.c:146 #11 0x00007f8c9c80c7cd in mod_init () at dialog.c:700 #12 0x00000000004f884d in init_mod (m=0x7f8ca88e82d8) at sr_module.c:967 #13 0x00000000004f8703 in init_mod (m=0x7f8ca88e8f98) at sr_module.c:964 #14 0x00000000004f8703 in init_mod (m=0x7f8ca88e94c0) at sr_module.c:964
(gdb) bt full #0 0x0000003196e32625 in raise () from /lib64/libc.so.6 No symbol table info available. #1 0x0000003196e33e05 in abort () from /lib64/libc.so.6 No symbol table info available. #2 0x000000000049138f in get_max_procs () at pt.c:165 __FUNCTION__ = "get_max_procs" #3 0x00007f8ca8655106 in init_tls_h () at tls_init.c:598 ssl_version = 268439647 lib_kerberos = 1 lib_zlib = 1 kerberos_support = 1 comp_support = 1 lib_cflags = 0x319a1dede0 "compiler: gcc -fPIC -DOPENSSL_PIC -DZLIB -DOPENSSL_THREADS -D_REENTRANT -DDSO_DLFCN -DHAVE_DLFCN_H -DKRB5_MIT -m64 -DL_ENDIAN -DTERMIO -Wall -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fs"... low_mem_threshold1 = -1 low_mem_threshold2 = -1 tls_grp = {s = 0x7fffcec76560 "\025", len = 0} s = {s = 0x7f8ca0010660 "db_postgres_new_connection", len = -1462250968} cfg_ctx = 0x7f8ca0010378 __FUNCTION__ = "init_tls_h" #4 0x00000000005372b9 in init_tls () at tls_hooks.c:70
#5 0x00007f8c9fffb655 in db_postgres_new_connection (id=0x7f8ca8d7d0b0) at km_pg_con.c:78 ptr = 0x7f8ca8d7d310 ports = 0x0 __FUNCTION__ = "db_postgres_new_connection" #6 0x00007f8c9fbd0eaa in db_do_init2 (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>, pooling=DB_POOLING_PERMITTED) at db.c:320 id = 0x7f8ca8d7d0b0 con = 0x0 res = 0x7f8ca8d7d008 con_size = 24 __FUNCTION__ = "db_do_init2" #7 0x00007f8c9fbd06d5 in db_do_init (url=0x7f8c9ca52cd0, new_connection=0x7f8c9fffac47 <db_postgres_new_connection>) at db.c:273 No locals. #8 0x00007f8c9fff4bbc in db_postgres_init (_url=0x7f8c9ca52cd0) at km_dbase.c:133 No locals. #9 0x00007f8c9c81429f in dlg_connect_db (db_url=0x7f8c9ca52cd0) at dlg_db_handler.c:132 __FUNCTION__ = "dlg_connect_db"
Kept the core in case you need it.
-
Daniel-Constantin Mierla -
James Cloos -
Olle E. Johansson -
Øyvind Kolbu