[SR-Users] db_mysql_new_connection(): driver error: Can't connect to MySQL server

Tue Nov 29 09:43:40 CET 2022

Hello!

It also seems to me that there are differences in the implementation of the
protocol, but so far I have not been able to find a significant difference
in the traces.
Tried some tests with an intermediate ProxySQL and it looks encouraging.

пн, 28 нояб. 2022 г. в 11:57, Henning Westerholt <hw at gilawa.com>:

> Hello,
>
>
>
> Interesting issue. Probably worth a try to look closer to the mysql
> protocol traces (e.g., with wireshark) and try to spot differences in the
> exchange at Kamailio startup for the working and non-working setup.
>
>
>
> Might be a slight incompatibility with the azure database implementation,
> observed something like this in the past with one project.
>
>
>
> Cheers,
>
>
>
> Henning
>
>
>
> --
>
> Henning Westerholt – https://skalatan.de/blog/
>
> Kamailio services – https://gilawa.com
>
>
>
> *From:* sr-users <sr-users-bounces at lists.kamailio.org> *On Behalf Of *Denys
> Pozniak
> *Sent:* Friday, November 25, 2022 5:09 PM
> *To:* Kamailio (SER) - Users Mailing List <sr-users at lists.kamailio.org>
> *Subject:* [SR-Users] db_mysql_new_connection(): driver error: Can't
> connect to MySQL server
>
>
>
> Hello!
>
>
>
> We use Kamailio in conjunction with the cloud Azure Database for MySQL
> 5.7. It has been noticed that Kamailio does not always start after
> restarting.
>
> It happens to restart a couple of times and everything starts normally.
>
> From the pickup trace I collect on our side, it can be seen that Kamailio
> connects to MySQL, requests and gets data, and then sends a Request Quit.
>
> On another server with a different configuration (slightly different set
> of modules) and connected to the same database, this issue is not
> reproduced.
>
>
>
> How to determine the source of the problem?
>
>
>
> Below, the logs are filtered by PID of processes in which an error
> occurred:
>
> ERROR: db_mysql [km_my_con.c:163]: db_mysql_new_connection(): driver
> error: Can't connect to MySQL server on '10.1.128.4' (110)
>
>
>
>
>
> 11(588460) DEBUG: <core> [core/pt.c:308]: fork_process(): seeding PRNG
> with 893384711
>
> 11(588460) DEBUG: <core> [core/rand/cryptorand.c:36]: cryptorand_seed():
> seeding cryptorand generator with 893384711
>
> 11(588460) DEBUG: <core> [core/rand/fortuna/random.c:175]:
> sr_add_entropy(): additional 4 bytes entropy added to cryptographic PRNG
>
> 11(588460) DEBUG: <core> [core/pt.c:313]: fork_process(): test random
> numbers 289569343 1482836098 4036842274 2495827489
>
> 11(588460) DEBUG: <core> [core/sr_module.c:926]: init_child():
> initializing PROC_RPC with rank -2
>
> 11(588460) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 11
> rank -2: jsonrpcs [DMQ WORKER]
>
> 11(588460) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 11
> rank -2: kex [DMQ WORKER]
>
> 11(588460) DEBUG: kex [kex_mod.c:155]: child_init(): rank is (-2)
>
> 11(588460) DEBUG: <core> [core/utils/sruid.c:121]: sruid_init(): root for
> sruid is [srid-6380d27f-8faac-] (0 / 20)
>
> 11(588460) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 11
> rank -2: corex [DMQ WORKER]
>
> 11(588460) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 11
> rank -2: tm [DMQ WORKER]
>
> 11(588460) DEBUG: tm [callid.c:136]: child_init_callid(): callid: '
> 558fadb265b2cc20-588460 at 10.1.15.12'
>
> 11(588460) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 11
> rank -2: tmx [DMQ WORKER]
>
> 11(588460) DEBUG: tmx [tmx_mod.c:262]: child_init(): rank is (-2)
>
> 11(588460) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 11
> rank -2: sl [DMQ WORKER]
>
> 11(588460) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 11
> rank -2: usrloc [DMQ WORKER]
>
> 11(588460) DEBUG: <core> [core/utils/sruid.c:121]: sruid_init(): root for
> sruid is [ulcx-6380d27f-8faac-] (0 / 20)
>
> 11(588460) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 11
> rank -2: registrar [DMQ WORKER]
>
> 11(588460) DEBUG: <core> [core/utils/sruid.c:121]: sruid_init(): root for
> sruid is [uloc-6380d27f-8faac-] (0 / 20)
>
> 11(588460) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 11
> rank -2: ctl [DMQ WORKER]
>
> 11(588460) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 11
> rank -2: dmq [DMQ WORKER]
>
> 11(588460) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 11
> rank -2: auth_db [DMQ WORKER]
>
> 11(588460) DEBUG: <core> [db.c:315]: db_do_init2(): connection 0x
> 7f96e7d58880 not found in pool
>
> 11(588460) DEBUG: db_mysql [km_my_con.c:110]: db_mysql_new_connection():
> opening connection: mysql://xxxx:xxxx@10.1.128.4/kamailio
>
> 11(588460) ERROR: db_mysql [km_my_con.c:163]: db_mysql_new_connection():
> driver error: Can't connect to MySQL server on '10.1.128.4' (110)
>
> 11(588460) ERROR: <core> [db.c:319]: db_do_init2(): could not add
> connection to the pool
>
> 11(588460) ERROR: auth_db [auth_db_mod.c:161]: child_init(): unable to
> connect to the database
>
> 11(588460) ERROR: <core> [core/sr_module.c:882]: init_mod_child(): error
> while initializing module auth_db
> (/usr/lib/x86_64-linux-gnu/kamailio/modules/auth_db.so) (idx: 11 rank: -2
> desc: [DMQ WORKER])
>
> 11(588460) ERROR: <core> [core/pt.c:338]: fork_process(): init_child
> failed for process 11, pid 588460, "DMQ WORKER"
>
> 11(588460) ERROR: dmq [dmq.c:314]: child_init(): failed to fork worker
> process 0
>
> 11(588460) ERROR: <core> [core/sr_module.c:882]: init_mod_child(): error
> while initializing module dmq
> (/usr/lib/x86_64-linux-gnu/kamailio/modules/dmq.so) (idx: 11 rank: 0
> desc: [DMQ WORKER])
>
> 11(588460) ERROR: <core> [main.c:1842]: main_loop(): error in init_child
>
>
>
>
>
> 17(588466) DEBUG: <core> [core/pt.c:308]: fork_process(): seeding PRNG
> with 2018260302
>
> 17(588466) DEBUG: <core> [core/rand/cryptorand.c:36]: cryptorand_seed():
> seeding cryptorand generator with 2018260302
>
> 17(588466) DEBUG: <core> [core/rand/fortuna/random.c:175]:
> sr_add_entropy(): additional 4 bytes entropy added to cryptographic PRNG
>
> 17(588466) DEBUG: <core> [core/pt.c:313]: fork_process(): test random
> numbers 1395463366 918020172 18663197 531231393
>
> 17(588466) DEBUG: <core> [core/sr_module.c:926]: init_child():
> initializing PROC_TIMER with rank -1
>
> 17(588466) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 17
> rank -1: jsonrpcs [Dialog Clean Timer]
>
> 17(588466) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 17
> rank -1: kex [Dialog Clean Timer]
>
> 17(588466) DEBUG: kex [kex_mod.c:155]: child_init(): rank is (-1)
>
> 17(588466) DEBUG: <core> [core/utils/sruid.c:121]: sruid_init(): root for
> sruid is [srid-6380d27f-8fab2-] (0 / 20)
>
> 17(588466) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 17
> rank -1: corex [Dialog Clean Timer]
>
> 17(588466) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 17
> rank -1: tm [Dialog Clean Timer]
>
> 17(588466) DEBUG: tm [callid.c:136]: child_init_callid(): callid: '
> 558fadb265b2cc20-588466 at 10.1.15.12'
>
> 17(588466) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 17
> rank -1: tmx [Dialog Clean Timer]
>
> 17(588466) DEBUG: tmx [tmx_mod.c:262]: child_init(): rank is (-1)
>
> 17(588466) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 17
> rank -1: sl [Dialog Clean Timer]
>
> 17(588466) DEBUG: <core> [core/sr_module.c:878]: init_mod_child(): idx 17
> rank -1: usrloc [Dialog Clean Timer]
>
> 17(588466) DEBUG: <core> [core/utils/sruid.c:121]: sruid_init(): root for
> sruid is [ulcx-6380d27f-8fab2-] (0 / 20)
>
> 17(588466) DEBUG: <core> [db.c:315]: db_do_init2(): connection 0x
> 7f96e7d58880 not found in pool
>
> 17(588466) DEBUG: db_mysql [km_my_con.c:110]: db_mysql_new_connection():
> opening connection: mysql://xxxx:xxxx@10.1.128.4/kamailio
>
> 17(588466) ERROR: db_mysql [km_my_con.c:163]: db_mysql_new_connection():
> driver error: Can't connect to MySQL server on '10.1.128.4' (110)
>
> 17(588466) ERROR: <core> [db.c:319]: db_do_init2(): could not add
> connection to the pool
>
> 17(588466) ERROR: usrloc [usrloc_mod.c:485]: child_init(): child(-1):
> failed to connect to database
>
> 17(588466) ERROR: <core> [core/sr_module.c:882]: init_mod_child(): error
> while initializing module usrloc
> (/usr/lib/x86_64-linux-gnu/kamailio/modules/usrloc.so) (idx: 17 rank: -1
> desc: [Dialog Clean Timer])
>
> 17(588466) ERROR: <core> [core/pt.c:338]: fork_process(): init_child
> failed for process 17, pid 588466, "Dialog Clean Timer"
>
> 17(588466) ERROR: dialog [dialog.c:782]: child_init(): failed to start
> clean timer routine as process
>
> 17(588466) ERROR: <core> [core/sr_module.c:882]: init_mod_child(): error
> while initializing module dialog
> (/usr/lib/x86_64-linux-gnu/kamailio/modules/dialog.so) (idx: 17 rank: 0
> desc: [Dialog Clean Timer])
>
> 17(588466) ERROR: <core> [main.c:1842]: main_loop(): error in init_child
>
> 17(588466) CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG:
> freeing already freed pointer (0x7f96e2f84650), called from tls:
> tls_init.c: ser_free(323), first free tls: tls_init.c: ser_free(323) -
> ignoring
>
> 17(588466) CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG:
> freeing already freed pointer (0x7f96e2f84900), called from tls:
> tls_init.c: ser_free(323), first free tls: tls_init.c: ser_malloc(293) -
> ignoring
>
> 17(588466) CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG:
> freeing already freed pointer (0x7f96e2fd50b0), called from tls:
> tls_init.c: ser_free(323), first free tls: tls_init.c: ser_free(323) -
> ignoring
>
> 17(588466) CRITICAL: <core> [core/mem/q_malloc.c:519]: qm_free(): BUG:
> freeing already freed pointer (0x7f96e2f820e0), called from tls:
> tls_init.c: ser_free(323), first free tls: tls_init.c: ser_free(323) -
> ignoring
>
>
>
> - Debian 11.5
>
> - libmariadb version 3.1.16
>
> -modules: auth_db, permissions, domain, rtpengine, dispatcher, dialog,
> uac, carrierroute, topos, acc
>
> - kamailio 5.6.2 (x86_64/linux)
> flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS,
> DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, Q_MALLOC,
> F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT,
> USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLOCKLIST,
> HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED
>
> ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_URI_SIZE 1024,
> BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
> poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
> id: unknown
> compiled with gcc 10.2.1
>
>
>
>
>
> --
>
>
>
> BR,
>
> Denys Pozniak
>
>
>
>
>

-- 

BR,
Denys Pozniak
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20221129/a89dd8ea/attachment.htm>