Daniel-Constantin Mierla writes: Nothing comes to syslog when register request arrives. Also kamailio does not respond to ctl command. Below is sample on what comes to syslog after start. -- Juha root@char:/var/www/manager# Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: ERROR: rtpengine [rtpengine.c:2667]: send_rtpp_command(): timeout waiting reply for command "" from RTP proxy <udp:192.26.134.10:6050> Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: ERROR: rtpengine [rtpengine.c:2541]: rtpp_test(): proxy did not respond to ping Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: rtpengine [rtpengine.c:668]: bind_force_send_ip(): force_send_ip_str not specified in .cfg file! Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: rtpengine [rtpengine.c:2518]: rtpp_test(): rtpp udp:192.26.134.10:6050 disabled for ever Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: mtree [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db.c:314]: db_do_init2(): connection 0x7f72f324a610 not found in pool Dec 24 12:29:41 char /usr/bin/sip-proxy[20315]: DEBUG: rtpengine [rtpengine.c:668]: bind_force_send_ip(): force_send_ip_str not specified in .cfg file! Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_my_con.c:107]: db_mysql_new_connection(): opening connection: mysql://xxxx:xxxx@127.0.0.1/sip_proxy Dec 24 12:29:41 char /usr/bin/sip-proxy[20315]: INFO: rtpengine [rtpengine.c:2551]: rtpp_test(): rtp proxy <udp:127.0.0.1:6050> found, support for it enabled Dec 24 12:29:41 char /usr/bin/sip-proxy[20315]: DEBUG: rtpengine [rtpengine.c:668]: bind_force_send_ip(): force_send_ip_str not specified in .cfg file! Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_my_con.c:146]: db_mysql_new_connection(): connection type is 127.0.0.1 via TCP/IP Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_my_con.c:147]: db_mysql_new_connection(): protocol version is 10 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_my_con.c:148]: db_mysql_new_connection(): server version is 10.1.37-MariaDB-0+deb9u1 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: mtree [mtree_mod.c:344]: child_init(): #3: database connection opened successfully Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: sipdump [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: siptrace [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db.c:314]: db_do_init2(): connection 0x7f72f32b19b0 not found in pool Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_my_con.c:107]: db_mysql_new_connection(): opening connection: mysql://xxxx:xxxx@127.0.0.1/sip_proxy_usage Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_my_con.c:146]: db_mysql_new_connection(): connection type is 127.0.0.1 via TCP/IP Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_my_con.c:147]: db_mysql_new_connection(): protocol version is 10 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_my_con.c:148]: db_mysql_new_connection(): server version is 10.1.37-MariaDB-0+deb9u1 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_res.c:119]: db_new_result(): allocate 56 bytes for result set at 0x7f72f32fd570 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_res.c:67]: db_mysql_get_columns(): 1 columns returned from the query Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_res.c:156]: db_allocate_columns(): allocate 8 bytes for result names at 0x7f72f32ed3b0 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_res.c:167]: db_allocate_columns(): allocate 4 bytes for result types at 0x7f72f3495140 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_res.c:84]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7f72f3495170 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_res.c:91]: db_mysql_get_columns(): RES_NAMES(0x7f72f3495170)[0]=[table_version] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_res.c:105]: db_mysql_get_columns(): use DB1_INT result type Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_res.c:188]: db_allocate_rows(): allocate 16 bytes for rows at 0x7f72f305b780 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_row.c:117]: db_allocate_row(): allocate 32 bytes for row values at 0x7f72f305b4c0 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_val.c:74]: db_str2val(): converting INT [4] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 1 columns Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7f72f3495170 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_res.c:96]: db_free_columns(): freeing result names at 0x7f72f32ed3b0 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_res.c:101]: db_free_columns(): freeing result types at 0x7f72f3495140 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_res.c:52]: db_free_rows(): freeing 1 rows Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_row.c:95]: db_free_row(): freeing row values at 0x7f72f305b4c0 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_res.c:60]: db_free_rows(): freeing rows at 0x7f72f305b780 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db_res.c:138]: db_free_result(): freeing result set at 0x7f72f32fd570 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: sl [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: tls [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: websocket [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: tmx [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: tmx [tmx_mod.c:258]: child_init(): rank is (3) Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: sqlops [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:618]: find_mod_export_record(): found export of <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/sip-proxy/modules/db_mysql.so] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db.c:209]: db_bind_mod(): using db bind api for db_mysql Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f32b0a80 found in pool Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:618]: find_mod_export_record(): found export of <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/sip-proxy/modules/db_mysql.so] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db.c:209]: db_bind_mod(): using db bind api for db_mysql Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db.c:314]: db_do_init2(): connection 0x7f72f32b0a80 not found in pool Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_my_con.c:107]: db_mysql_new_connection(): opening connection: mysql://xxxx:xxxx@127.0.0.1/sip_proxy_cache Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_my_con.c:146]: db_mysql_new_connection(): connection type is 127.0.0.1 via TCP/IP Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_my_con.c:147]: db_mysql_new_connection(): protocol version is 10 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: db_mysql [km_my_con.c:148]: db_mysql_new_connection(): server version is 10.1.37-MariaDB-0+deb9u1 Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:618]: find_mod_export_record(): found export of <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/sip-proxy/modules/db_mysql.so] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db.c:209]: db_bind_mod(): using db bind api for db_mysql Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: domain [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: usrloc [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [sruid.c:105]: sruid_init(): root for sruid is [ulcx-5c20b515-4f5d-] (0 / 19) Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: registrar [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [sruid.c:105]: sruid_init(): root for sruid is [uloc-5c20b515-4f5d-] (0 / 19) Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: acc [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: auth_db [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: permissions [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: uac_redirect [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [sruid.c:105]: sruid_init(): root for sruid is [rdir-5c20b515-4f5d-] (0 / 19) Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: nathelper [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: msilo [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: msilo [msilo.c:458]: child_init(): rank #3 / pid <20317> Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: msilo [msilo.c:477]: child_init(): #3 database connection opened successfully Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: htable [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: htable [htable.c:245]: child_init(): rank is (3) Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: kex [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: kex [kex_mod.c:155]: child_init(): rank is (3) Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [sruid.c:105]: sruid_init(): root for sruid is [srid-5c20b515-4f5d-] (0 / 19) Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: rtimer [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: pua [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: pua [pua.c:312]: child_init(): child 3: Database connection opened successfully Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: local [udp receiver child=2 sock=192.168.43.107:5060] Dec 24 12:29:41 char /usr/bin/sip-proxy[20317]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 3 rank 3: tcpops [udp receiver child=2 sock=192.168.43.107:5060] ^C root@char:/var/www/manager# Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: ERROR: rtpengine [rtpengine.c:2667]: send_rtpp_command(): timeout waiting reply for command "" from RTP proxy <udp:192.26.134.10:6050> Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: ERROR: rtpengine [rtpengine.c:2541]: rtpp_test(): proxy did not respond to ping Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: rtpengine [rtpengine.c:668]: bind_force_send_ip(): force_send_ip_str not specified in .cfg file! Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: rtpengine [rtpengine.c:2518]: rtpp_test(): rtpp udp:192.26.134.10:6050 disabled for ever Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: mtree [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db.c:314]: db_do_init2(): connection 0x7f72f324a610 not found in pool Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_my_con.c:107]: db_mysql_new_connection(): opening connection: mysql://xxxx:xxxx@127.0.0.1/sip_proxy Dec 24 12:29:46 char /usr/bin/sip-proxy[20316]: DEBUG: rtpengine [rtpengine.c:668]: bind_force_send_ip(): force_send_ip_str not specified in .cfg file! Dec 24 12:29:46 char /usr/bin/sip-proxy[20316]: INFO: rtpengine [rtpengine.c:2551]: rtpp_test(): rtp proxy <udp:127.0.0.1:6050> found, support for it enabled Dec 24 12:29:46 char /usr/bin/sip-proxy[20316]: DEBUG: rtpengine [rtpengine.c:668]: bind_force_send_ip(): force_send_ip_str not specified in .cfg file! Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_my_con.c:146]: db_mysql_new_connection(): connection type is 127.0.0.1 via TCP/IP Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_my_con.c:147]: db_mysql_new_connection(): protocol version is 10 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_my_con.c:148]: db_mysql_new_connection(): server version is 10.1.37-MariaDB-0+deb9u1 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: mtree [mtree_mod.c:344]: child_init(): #1: database connection opened successfully Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: sipdump [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: siptrace [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db.c:314]: db_do_init2(): connection 0x7f72f32b19b0 not found in pool Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_my_con.c:107]: db_mysql_new_connection(): opening connection: mysql://xxxx:xxxx@127.0.0.1/sip_proxy_usage Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_my_con.c:146]: db_mysql_new_connection(): connection type is 127.0.0.1 via TCP/IP Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_my_con.c:147]: db_mysql_new_connection(): protocol version is 10 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_my_con.c:148]: db_mysql_new_connection(): server version is 10.1.37-MariaDB-0+deb9u1 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_res.c:119]: db_new_result(): allocate 56 bytes for result set at 0x7f72f32fd570 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_res.c:67]: db_mysql_get_columns(): 1 columns returned from the query Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_res.c:156]: db_allocate_columns(): allocate 8 bytes for result names at 0x7f72f32ed3b0 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_res.c:167]: db_allocate_columns(): allocate 4 bytes for result types at 0x7f72f3495140 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_res.c:84]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7f72f3495170 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_res.c:91]: db_mysql_get_columns(): RES_NAMES(0x7f72f3495170)[0]=[table_version] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_res.c:105]: db_mysql_get_columns(): use DB1_INT result type Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_res.c:188]: db_allocate_rows(): allocate 16 bytes for rows at 0x7f72f305b780 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_row.c:117]: db_allocate_row(): allocate 32 bytes for row values at 0x7f72f305b4c0 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_val.c:74]: db_str2val(): converting INT [4] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 1 columns Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7f72f3495170 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_res.c:96]: db_free_columns(): freeing result names at 0x7f72f32ed3b0 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_res.c:101]: db_free_columns(): freeing result types at 0x7f72f3495140 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_res.c:52]: db_free_rows(): freeing 1 rows Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_row.c:95]: db_free_row(): freeing row values at 0x7f72f305b4c0 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_res.c:60]: db_free_rows(): freeing rows at 0x7f72f305b780 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db_res.c:138]: db_free_result(): freeing result set at 0x7f72f32fd570 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: sl [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: tls [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: websocket [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: tmx [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: tmx [tmx_mod.c:258]: child_init(): rank is (1) Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: sqlops [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:618]: find_mod_export_record(): found export of <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/sip-proxy/modules/db_mysql.so] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db.c:209]: db_bind_mod(): using db bind api for db_mysql Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f32b0a80 found in pool Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:618]: find_mod_export_record(): found export of <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/sip-proxy/modules/db_mysql.so] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db.c:209]: db_bind_mod(): using db bind api for db_mysql Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db.c:314]: db_do_init2(): connection 0x7f72f32b0a80 not found in pool Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_my_con.c:107]: db_mysql_new_connection(): opening connection: mysql://xxxx:xxxx@127.0.0.1/sip_proxy_cache Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_my_con.c:146]: db_mysql_new_connection(): connection type is 127.0.0.1 via TCP/IP Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_my_con.c:147]: db_mysql_new_connection(): protocol version is 10 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: db_mysql [km_my_con.c:148]: db_mysql_new_connection(): server version is 10.1.37-MariaDB-0+deb9u1 Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:618]: find_mod_export_record(): found export of <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/sip-proxy/modules/db_mysql.so] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db.c:209]: db_bind_mod(): using db bind api for db_mysql Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: domain [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: usrloc [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [sruid.c:105]: sruid_init(): root for sruid is [ulcx-5c20b51a-4f5b-] (0 / 19) Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: registrar [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [sruid.c:105]: sruid_init(): root for sruid is [uloc-5c20b51a-4f5b-] (0 / 19) Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: acc [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: auth_db [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: permissions [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: uac_redirect [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [sruid.c:105]: sruid_init(): root for sruid is [rdir-5c20b51a-4f5b-] (0 / 19) Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: nathelper [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: msilo [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: msilo [msilo.c:458]: child_init(): rank #1 / pid <20315> Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: msilo [msilo.c:477]: child_init(): #1 database connection opened successfully Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: htable [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: htable [htable.c:245]: child_init(): rank is (1) Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: kex [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: kex [kex_mod.c:155]: child_init(): rank is (1) Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [sruid.c:105]: sruid_init(): root for sruid is [srid-5c20b51a-4f5b-] (0 / 19) Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: rtimer [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: pua [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: pua [pua.c:312]: child_init(): child 1: Database connection opened successfully Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: local [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 1 rank 1: tcpops [udp receiver child=0 sock=192.168.43.107:5060] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/action.c:1664]: run_child_one_init_route(): attempting to run event_route[core:worker-one-init] Dec 24 12:29:46 char /usr/bin/sip-proxy[20315]: DEBUG: <core> [core/route.c:129]: route_add(): mapping routing block (0x5643cd4f2080)[core:worker-one-init] to 10 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: ERROR: rtpengine [rtpengine.c:2667]: send_rtpp_command(): timeout waiting reply for command "" from RTP proxy <udp:192.26.134.10:6050> Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: ERROR: rtpengine [rtpengine.c:2541]: rtpp_test(): proxy did not respond to ping Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: rtpengine [rtpengine.c:668]: bind_force_send_ip(): force_send_ip_str not specified in .cfg file! Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: rtpengine [rtpengine.c:2518]: rtpp_test(): rtpp udp:192.26.134.10:6050 disabled for ever Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: mtree [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db.c:314]: db_do_init2(): connection 0x7f72f324a610 not found in pool Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_my_con.c:107]: db_mysql_new_connection(): opening connection: mysql://xxxx:xxxx@127.0.0.1/sip_proxy Dec 24 12:29:51 char /usr/bin/sip-proxy[20318]: DEBUG: rtpengine [rtpengine.c:668]: bind_force_send_ip(): force_send_ip_str not specified in .cfg file! Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_my_con.c:146]: db_mysql_new_connection(): connection type is 127.0.0.1 via TCP/IP Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_my_con.c:147]: db_mysql_new_connection(): protocol version is 10 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_my_con.c:148]: db_mysql_new_connection(): server version is 10.1.37-MariaDB-0+deb9u1 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: mtree [mtree_mod.c:344]: child_init(): #2: database connection opened successfully Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: sipdump [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: siptrace [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db.c:314]: db_do_init2(): connection 0x7f72f32b19b0 not found in pool Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_my_con.c:107]: db_mysql_new_connection(): opening connection: mysql://xxxx:xxxx@127.0.0.1/sip_proxy_usage Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_my_con.c:146]: db_mysql_new_connection(): connection type is 127.0.0.1 via TCP/IP Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_my_con.c:147]: db_mysql_new_connection(): protocol version is 10 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_my_con.c:148]: db_mysql_new_connection(): server version is 10.1.37-MariaDB-0+deb9u1 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_res.c:119]: db_new_result(): allocate 56 bytes for result set at 0x7f72f32fd570 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_res.c:67]: db_mysql_get_columns(): 1 columns returned from the query Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_res.c:156]: db_allocate_columns(): allocate 8 bytes for result names at 0x7f72f32ed3b0 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_res.c:167]: db_allocate_columns(): allocate 4 bytes for result types at 0x7f72f3495140 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_res.c:84]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7f72f3495170 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_res.c:91]: db_mysql_get_columns(): RES_NAMES(0x7f72f3495170)[0]=[table_version] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_res.c:105]: db_mysql_get_columns(): use DB1_INT result type Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_res.c:188]: db_allocate_rows(): allocate 16 bytes for rows at 0x7f72f305b780 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_row.c:117]: db_allocate_row(): allocate 32 bytes for row values at 0x7f72f305b4c0 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_val.c:74]: db_str2val(): converting INT [4] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 1 columns Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7f72f3495170 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_res.c:96]: db_free_columns(): freeing result names at 0x7f72f32ed3b0 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_res.c:101]: db_free_columns(): freeing result types at 0x7f72f3495140 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_res.c:52]: db_free_rows(): freeing 1 rows Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_row.c:95]: db_free_row(): freeing row values at 0x7f72f305b4c0 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_res.c:60]: db_free_rows(): freeing rows at 0x7f72f305b780 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db_res.c:138]: db_free_result(): freeing result set at 0x7f72f32fd570 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: sl [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: tls [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: websocket [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: tmx [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: tmx [tmx_mod.c:258]: child_init(): rank is (2) Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: sqlops [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:618]: find_mod_export_record(): found export of <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/sip-proxy/modules/db_mysql.so] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db.c:209]: db_bind_mod(): using db bind api for db_mysql Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f32b0a80 found in pool Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:618]: find_mod_export_record(): found export of <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/sip-proxy/modules/db_mysql.so] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db.c:209]: db_bind_mod(): using db bind api for db_mysql Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db.c:314]: db_do_init2(): connection 0x7f72f32b0a80 not found in pool Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_my_con.c:107]: db_mysql_new_connection(): opening connection: mysql://xxxx:xxxx@127.0.0.1/sip_proxy_cache Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_my_con.c:146]: db_mysql_new_connection(): connection type is 127.0.0.1 via TCP/IP Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_my_con.c:147]: db_mysql_new_connection(): protocol version is 10 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: db_mysql [km_my_con.c:148]: db_mysql_new_connection(): server version is 10.1.37-MariaDB-0+deb9u1 Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:618]: find_mod_export_record(): found export of <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/sip-proxy/modules/db_mysql.so] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db.c:209]: db_bind_mod(): using db bind api for db_mysql Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: domain [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: usrloc [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [sruid.c:105]: sruid_init(): root for sruid is [ulcx-5c20b51f-4f5c-] (0 / 19) Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: registrar [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [sruid.c:105]: sruid_init(): root for sruid is [uloc-5c20b51f-4f5c-] (0 / 19) Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: acc [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: auth_db [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: permissions [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: uac_redirect [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [sruid.c:105]: sruid_init(): root for sruid is [rdir-5c20b51f-4f5c-] (0 / 19) Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: nathelper [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: msilo [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: msilo [msilo.c:458]: child_init(): rank #2 / pid <20316> Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: msilo [msilo.c:477]: child_init(): #2 database connection opened successfully Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: htable [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: htable [htable.c:245]: child_init(): rank is (2) Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: kex [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: kex [kex_mod.c:155]: child_init(): rank is (2) Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [sruid.c:105]: sruid_init(): root for sruid is [srid-5c20b51f-4f5c-] (0 / 19) Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: rtimer [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: pua [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: pua [pua.c:312]: child_init(): child 2: Database connection opened successfully Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: local [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20316]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 2 rank 2: tcpops [udp receiver child=1 sock=192.168.43.107:5060] Dec 24 12:29:51 char /usr/bin/sip-proxy[20318]: INFO: rtpengine [rtpengine.c:2551]: rtpp_test(): rtp proxy <udp:127.0.0.1:6050> found, support for it enabled Dec 24 12:29:51 char /usr/bin/sip-proxy[20318]: DEBUG: rtpengine [rtpengine.c:668]: bind_force_send_ip(): force_send_ip_str not specified in .cfg file! Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: ERROR: rtpengine [rtpengine.c:2667]: send_rtpp_command(): timeout waiting reply for command "" from RTP proxy <udp:192.26.134.10:6050> Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: ERROR: rtpengine [rtpengine.c:2541]: rtpp_test(): proxy did not respond to ping Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: rtpengine [rtpengine.c:668]: bind_force_send_ip(): force_send_ip_str not specified in .cfg file! Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: rtpengine [rtpengine.c:2518]: rtpp_test(): rtpp udp:192.26.134.10:6050 disabled for ever Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 4 rank 4: mtree [udp receiver child=3 sock=192.168.43.107:5060] Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db.c:314]: db_do_init2(): connection 0x7f72f324a610 not found in pool Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_my_con.c:107]: db_mysql_new_connection(): opening connection: mysql://xxxx:xxxx@127.0.0.1/sip_proxy Dec 24 12:29:56 char /usr/bin/sip-proxy[20321]: DEBUG: rtpengine [rtpengine.c:668]: bind_force_send_ip(): force_send_ip_str not specified in .cfg file! Dec 24 12:29:56 char /usr/bin/sip-proxy[20321]: INFO: rtpengine [rtpengine.c:2551]: rtpp_test(): rtp proxy <udp:127.0.0.1:6050> found, support for it enabled Dec 24 12:29:56 char /usr/bin/sip-proxy[20321]: DEBUG: rtpengine [rtpengine.c:668]: bind_force_send_ip(): force_send_ip_str not specified in .cfg file! Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_my_con.c:146]: db_mysql_new_connection(): connection type is 127.0.0.1 via TCP/IP Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_my_con.c:147]: db_mysql_new_connection(): protocol version is 10 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_my_con.c:148]: db_mysql_new_connection(): server version is 10.1.37-MariaDB-0+deb9u1 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: mtree [mtree_mod.c:344]: child_init(): #4: database connection opened successfully Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 4 rank 4: sipdump [udp receiver child=3 sock=192.168.43.107:5060] Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 4 rank 4: siptrace [udp receiver child=3 sock=192.168.43.107:5060] Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db.c:314]: db_do_init2(): connection 0x7f72f32b19b0 not found in pool Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_my_con.c:107]: db_mysql_new_connection(): opening connection: mysql://xxxx:xxxx@127.0.0.1/sip_proxy_usage Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_my_con.c:146]: db_mysql_new_connection(): connection type is 127.0.0.1 via TCP/IP Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_my_con.c:147]: db_mysql_new_connection(): protocol version is 10 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_my_con.c:148]: db_mysql_new_connection(): server version is 10.1.37-MariaDB-0+deb9u1 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_res.c:119]: db_new_result(): allocate 56 bytes for result set at 0x7f72f32fd570 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_res.c:67]: db_mysql_get_columns(): 1 columns returned from the query Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_res.c:156]: db_allocate_columns(): allocate 8 bytes for result names at 0x7f72f32ed3b0 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_res.c:167]: db_allocate_columns(): allocate 4 bytes for result types at 0x7f72f3495140 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_res.c:84]: db_mysql_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7f72f3495170 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_res.c:91]: db_mysql_get_columns(): RES_NAMES(0x7f72f3495170)[0]=[table_version] Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_res.c:105]: db_mysql_get_columns(): use DB1_INT result type Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_res.c:188]: db_allocate_rows(): allocate 16 bytes for rows at 0x7f72f305b780 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_row.c:117]: db_allocate_row(): allocate 32 bytes for row values at 0x7f72f305b4c0 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_val.c:74]: db_str2val(): converting INT [4] Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 1 columns Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7f72f3495170 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_res.c:96]: db_free_columns(): freeing result names at 0x7f72f32ed3b0 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_res.c:101]: db_free_columns(): freeing result types at 0x7f72f3495140 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_res.c:52]: db_free_rows(): freeing 1 rows Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_row.c:95]: db_free_row(): freeing row values at 0x7f72f305b4c0 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_res.c:60]: db_free_rows(): freeing rows at 0x7f72f305b780 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db_res.c:138]: db_free_result(): freeing result set at 0x7f72f32fd570 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 4 rank 4: sl [udp receiver child=3 sock=192.168.43.107:5060] Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 4 rank 4: tls [udp receiver child=3 sock=192.168.43.107:5060] Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 4 rank 4: websocket [udp receiver child=3 sock=192.168.43.107:5060] Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 4 rank 4: tmx [udp receiver child=3 sock=192.168.43.107:5060] Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: tmx [tmx_mod.c:258]: child_init(): rank is (4) Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [core/sr_module.c:841]: init_mod_child(): idx 4 rank 4: sqlops [udp receiver child=3 sock=192.168.43.107:5060] Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [core/sr_module.c:618]: find_mod_export_record(): found export of <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/sip-proxy/modules/db_mysql.so] Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db.c:209]: db_bind_mod(): using db bind api for db_mysql Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f32b0a80 found in pool Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [core/sr_module.c:618]: find_mod_export_record(): found export of <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/sip-proxy/modules/db_mysql.so] Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db.c:209]: db_bind_mod(): using db bind api for db_mysql Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db.c:314]: db_do_init2(): connection 0x7f72f32b0a80 not found in pool Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_my_con.c:107]: db_mysql_new_connection(): opening connection: mysql://xxxx:xxxx@127.0.0.1/sip_proxy_cache Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_my_con.c:146]: db_mysql_new_connection(): connection type is 127.0.0.1 via TCP/IP Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_my_con.c:147]: db_mysql_new_connection(): protocol version is 10 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: db_mysql [km_my_con.c:148]: db_mysql_new_connection(): server version is 10.1.37-MariaDB-0+deb9u1 Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [core/sr_module.c:618]: find_mod_export_record(): found export of <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/sip-proxy/modules/db_mysql.so] Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db.c:209]: db_bind_mod(): using db bind api for db_mysql Dec 24 12:29:56 char /usr/bin/sip-proxy[20318]: DEBUG: <core> [db.c:323]: db_do_init2(): connection 0x7f72f332e090 found in pool

Daniel-Constantin Mierla writes: Same number of processes when I start K with proper rtpengine set and with one that has an rtpengine that does not respond. There is 41 processes. Below is a few different ones. -- Juha --------------- #0 0x00007f9958d04210 in __pause_nocancel () at ../sysdeps/unix/syscall-template.S:84 #1 0x000055ce69f98509 in main_loop () at main.c:1755 #2 0x000055ce69f9eb39 in main (argc=17, argv=0x7ffd8be61d18) at main.c:2645 #0 0x00007f9958d359c3 in __recvfrom_nocancel () at ../sysdeps/unix/syscall-template.S:84 #1 0x000055ce6a029443 in udp_rcv_loop () at core/udp_server.c:460 #2 0x000055ce69f969cf in main_loop () at main.c:1621 #3 0x000055ce69f9eb39 in main (argc=17, argv=0x7ffd8be61d18) at main.c:2645 #0 0x00007f9958c7fe89 in __GI___sigwaitinfo (set=<optimized out>, info=0x0) at ../sysdeps/unix/sysv/linux/sigwaitinfo.c:56 #1 0x000055ce6a04c36a in slow_timer_main () at core/timer.c:1093 #2 0x000055ce69f971ab in main_loop () at main.c:1677 #3 0x000055ce69f9eb39 in main (argc=17, argv=0x7ffd8be61d18) at main.c:2645 #0 0x00007f9958d359c3 in __recvfrom_nocancel () at ../sysdeps/unix/syscall-template.S:84 #1 0x000055ce6a153168 in async_task_run (idx=1) at core/async_task.c:269 #2 0x000055ce6a151f9c in async_task_child_init (rank=0) at core/async_task.c:185 #3 0x000055ce6a0d5e3a in init_child (rank=0) at core/sr_module.c:867 #4 0x000055ce69f977cc in main_loop () at main.c:1703 #5 0x000055ce69f9eb39 in main (argc=17, argv=0x7ffd8be61d18) at main.c:2645 #0 0x00007f9958d350a3 in __epoll_wait_nocancel () at ../sysdeps/unix/syscall-template.S:84 #1 0x00007f99554117e7 in io_wait_loop_epoll (h=0x7f9955643340 <io_h>, t=10, repeat=0) at ../../core/io_wait.h:1034 #2 0x00007f9955415d1a in io_listen_loop (fd_no=1, cs_lst=0x55ce6c6b6680) at io_listener.c:281 #3 0x00007f9955431c4c in mod_child (rank=0) at ctl.c:338 #4 0x000055ce6a0d5a84 in init_mod_child (m=0x7f99580b0ea0, rank=0) at core/sr_module.c:843 #5 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b12d0, rank=0) at core/sr_module.c:839 #6 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b1600, rank=0) at core/sr_module.c:839 #7 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b1ac0, rank=0) at core/sr_module.c:839 #8 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b1ee0, rank=0) at core/sr_module.c:839 #9 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b2720, rank=0) at core/sr_module.c:839 #10 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b2a30, rank=0) at core/sr_module.c:839 #11 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b3210, rank=0) at core/sr_module.c:839 #12 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b34a0, rank=0) at core/sr_module.c:839 #13 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b36f0, rank=0) at core/sr_module.c:839 #14 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b3a20, rank=0) at core/sr_module.c:839 #15 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b4270, rank=0) at core/sr_module.c:839 #16 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b44c0, rank=0) at core/sr_module.c:839 #17 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b47f0, rank=0) at core/sr_module.c:839 #18 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b4c80, rank=0) at core/sr_module.c:839 #19 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b5250, rank=0) at core/sr_module.c:839 #20 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b6e20, rank=0) at core/sr_module.c:839 #21 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b7490, rank=0) at core/sr_module.c:839 #22 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b77a0, rank=0) at core/sr_module.c:839 #23 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b7b20, rank=0) at core/sr_module.c:839 #24 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b7d70, rank=0) at core/sr_module.c:839 #25 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b87d0, rank=0) at core/sr_module.c:839 #26 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b8f50, rank=0) at core/sr_module.c:839 #27 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b95d0, rank=0) at core/sr_module.c:839 #28 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580be830, rank=0) at core/sr_module.c:839 #29 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580beeb0, rank=0) at core/sr_module.c:839 #30 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580bf220, rank=0) at core/sr_module.c:839 #31 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580bf5c0, rank=0) at core/sr_module.c:839 #32 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580bf810, rank=0) at core/sr_module.c:839 #33 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580bfea0, rank=0) at core/sr_module.c:839 #34 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c01a0, rank=0) at core/sr_module.c:839 #35 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c0580, rank=0) at core/sr_module.c:839 #36 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c0f90, rank=0) at core/sr_module.c:839 #37 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c14c0, rank=0) at core/sr_module.c:839 #38 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c17d0, rank=0) at core/sr_module.c:839 #39 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c1d90, rank=0) at core/sr_module.c:839 #40 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c1fe0, rank=0) at core/sr_module.c:839 #41 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c2310, rank=0) at core/sr_module.c:839 #42 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c2cf0, rank=0) at core/sr_module.c:839 #43 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c3340, rank=0) at core/sr_module.c:839 #44 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c3700, rank=0) at core/sr_module.c:839 #45 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c4590, rank=0) at core/sr_module.c:839 #46 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c47b0, rank=0) at core/sr_module.c:839 #47 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c49d0, rank=0) at core/sr_module.c:839 #48 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c4c90, rank=0) at core/sr_module.c:839 #49 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c5230, rank=0) at core/sr_module.c:839 #50 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c5530, rank=0) at core/sr_module.c:839 #51 0x000055ce6a0d5e59 in init_child (rank=0) at core/sr_module.c:870 #52 0x000055ce69f977cc in main_loop () at main.c:1703 #53 0x000055ce69f9eb39 in main (argc=17, argv=0x7ffd8be61d18) at main.c:2645 #0 0x00007f9958d2d3a3 in __select_nocancel () at ../sysdeps/unix/syscall-template.S:84 #1 0x000055ce6a185727 in sleep_us (nusecs=100) at core/ut.h:513 #2 0x000055ce6a185898 in fork_basic_utimer (child_id=-1, desc=0x7f994f19434a "SIPDUMP WRITE TIMER", make_sock=1, f=0x7f994f192e3c <sipdump_timer_exec>, param=0x0, uinterval=100) at core/timer_proc.c:116 #3 0x00007f994f18e782 in child_init (rank=0) at sipdump_mod.c:126 #4 0x000055ce6a0d5a84 in init_mod_child (m=0x7f99580b4270, rank=0) at core/sr_module.c:843 #5 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b44c0, rank=0) at core/sr_module.c:839 #6 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b47f0, rank=0) at core/sr_module.c:839 #7 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b4c80, rank=0) at core/sr_module.c:839 #8 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b5250, rank=0) at core/sr_module.c:839 #9 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b6e20, rank=0) at core/sr_module.c:839 #10 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b7490, rank=0) at core/sr_module.c:839 #11 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b77a0, rank=0) at core/sr_module.c:839 #12 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b7b20, rank=0) at core/sr_module.c:839 #13 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b7d70, rank=0) at core/sr_module.c:839 #14 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b87d0, rank=0) at core/sr_module.c:839 #15 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b8f50, rank=0) at core/sr_module.c:839 #16 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580b95d0, rank=0) at core/sr_module.c:839 #17 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580be830, rank=0) at core/sr_module.c:839 #18 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580beeb0, rank=0) at core/sr_module.c:839 #19 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580bf220, rank=0) at core/sr_module.c:839 #20 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580bf5c0, rank=0) at core/sr_module.c:839 #21 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580bf810, rank=0) at core/sr_module.c:839 #22 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580bfea0, rank=0) at core/sr_module.c:839 #23 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c01a0, rank=0) at core/sr_module.c:839 #24 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c0580, rank=0) at core/sr_module.c:839 #25 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c0f90, rank=0) at core/sr_module.c:839 #26 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c14c0, rank=0) at core/sr_module.c:839 #27 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c17d0, rank=0) at core/sr_module.c:839 #28 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c1d90, rank=0) at core/sr_module.c:839 #29 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c1fe0, rank=0) at core/sr_module.c:839 #30 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c2310, rank=0) at core/sr_module.c:839 #31 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c2cf0, rank=0) at core/sr_module.c:839 #32 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c3340, rank=0) at core/sr_module.c:839 #33 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c3700, rank=0) at core/sr_module.c:839 #34 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c4590, rank=0) at core/sr_module.c:839 #35 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c47b0, rank=0) at core/sr_module.c:839 #36 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c49d0, rank=0) at core/sr_module.c:839 #37 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c4c90, rank=0) at core/sr_module.c:839 #38 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c5230, rank=0) at core/sr_module.c:839 #39 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c5530, rank=0) at core/sr_module.c:839 #40 0x000055ce6a0d5e59 in init_child (rank=0) at core/sr_module.c:870 #41 0x000055ce69f977cc in main_loop () at main.c:1703 #42 0x000055ce69f9eb39 in main (argc=17, argv=0x7ffd8be61d18) at main.c:2645 #0 0x00007f9958d2d3a3 in __select_nocancel () at ../sysdeps/unix/syscall-template.S:84 #1 0x000055ce6a185727 in sleep_us (nusecs=60000000) at core/ut.h:513 #2 0x000055ce6a185a8b in fork_sync_timer (child_id=-1, desc=0x7f994466af8a "USRLOC Timer", make_sock=1, f=0x7f9944646573 <ul_local_timer>, param=0x0, interval=60000) at core/timer_proc.c:221 #3 0x00007f994464538a in child_init (_rank=0) at usrloc_mod.c:398 #4 0x000055ce6a0d5a84 in init_mod_child (m=0x7f99580bf5c0, rank=0) at core/sr_module.c:843 #5 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580bf810, rank=0) at core/sr_module.c:839 #6 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580bfea0, rank=0) at core/sr_module.c:839 #7 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c01a0, rank=0) at core/sr_module.c:839 #8 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c0580, rank=0) at core/sr_module.c:839 #9 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c0f90, rank=0) at core/sr_module.c:839 #10 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c14c0, rank=0) at core/sr_module.c:839 #11 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c17d0, rank=0) at core/sr_module.c:839 #12 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c1d90, rank=0) at core/sr_module.c:839 #13 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c1fe0, rank=0) at core/sr_module.c:839 #14 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c2310, rank=0) at core/sr_module.c:839 #15 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c2cf0, rank=0) at core/sr_module.c:839 #16 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c3340, rank=0) at core/sr_module.c:839 #17 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c3700, rank=0) at core/sr_module.c:839 #18 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c4590, rank=0) at core/sr_module.c:839 #19 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c47b0, rank=0) at core/sr_module.c:839 #20 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c49d0, rank=0) at core/sr_module.c:839 #21 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c4c90, rank=0) at core/sr_module.c:839 #22 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c5230, rank=0) at core/sr_module.c:839 #23 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c5530, rank=0) at core/sr_module.c:839 #24 0x000055ce6a0d5e59 in init_child (rank=0) at core/sr_module.c:870 #25 0x000055ce69f977cc in main_loop () at main.c:1703 #26 0x000055ce69f9eb39 in main (argc=17, argv=0x7ffd8be61d18) at main.c:2645 #0 0x00007f9958d04270 in __nanosleep_nocancel () at ../sysdeps/unix/syscall-template.S:84 #1 0x00007f9958d041da in __sleep (seconds=0) at ../sysdeps/posix/sleep.c:55 #2 0x000055ce6a1857d1 in fork_basic_timer (child_id=-1, desc=0x7ffd8be61540 "RTIMER EXEC child=0 timer=minute_timer", make_sock=1, f=0x7f994275d35a <stm_timer_exec>, param=0x7f99580d0190, interval=60) at core/timer_proc.c:77 #3 0x00007f994275cfd6 in child_init (rank=0) at rtimer_mod.c:166 #4 0x000055ce6a0d5a84 in init_mod_child (m=0x7f99580c4590, rank=0) at core/sr_module.c:843 #5 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c47b0, rank=0) at core/sr_module.c:839 #6 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c49d0, rank=0) at core/sr_module.c:839 #7 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c4c90, rank=0) at core/sr_module.c:839 #8 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c5230, rank=0) at core/sr_module.c:839 #9 0x000055ce6a0d5707 in init_mod_child (m=0x7f99580c5530, rank=0) at core/sr_module.c:839 #10 0x000055ce6a0d5e59 in init_child (rank=0) at core/sr_module.c:870 #11 0x000055ce69f977cc in main_loop () at main.c:1703 #12 0x000055ce69f9eb39 in main (argc=17, argv=0x7ffd8be61d18) at main.c:2645 #0 0x00007f9958d350a3 in __epoll_wait_nocancel () at ../sysdeps/unix/syscall-template.S:84 #1 0x000055ce6a1d2713 in io_wait_loop_epoll (h=0x55ce6a653fc0 <io_w>, t=2, repeat=0) at core/io_wait.h:1034 #2 0x000055ce6a1e77bb in tcp_receive_loop (unix_sock=45) at core/tcp_read.c:1974 #3 0x000055ce6a09ae90 in tcp_init_children () at core/tcp_main.c:4853 #4 0x000055ce69f97ab2 in main_loop () at main.c:1711 #5 0x000055ce69f9eb39 in main (argc=17, argv=0x7ffd8be61d18) at main.c:2645 #0 0x00007f9958d350a3 in __epoll_wait_nocancel () at ../sysdeps/unix/syscall-template.S:84 #1 0x000055ce6a05f47a in io_wait_loop_epoll (h=0x55ce6a60adc0 <io_h>, t=5, repeat=0) at core/io_wait.h:1034 #2 0x000055ce6a0971d1 in tcp_main_loop () at core/tcp_main.c:4547 #3 0x000055ce69f97e0c in main_loop () at main.c:1719 #4 0x000055ce69f9eb39 in main (argc=17, argv=0x7ffd8be61d18) at main.c:2645

Daniel-Constantin Mierla writes: No, via tcp and there was also tcp listener processes. -- Juha

Daniel-Constantin Mierla writes: Yes, UDP register is sent, but kamailio does not respond to it. Then I did this. 1) Started K where rtpengine udp:192.26.134.10:6050 is enabled but is not running. 2) Gave kamcmd command. It two about two minutes before I got the prompt. 3) Gave 'rtpengine.show all' command. It took perhaps 30 seconds to produce: { url: udp:127.0.0.1:6050 set: 0 index: 0 weight: 10 disabled: 0 recheck_ticks: 0 } { url: udp:192.26.134.10:6050 set: 0 index: 2 weight: 1 disabled: 1 recheck_ticks: 60 } { url: udp:192.26.134.10:6050 set: 1 index: 1 weight: 1 disabled: 1(permanent) recheck_ticks: N/A } Now udp:192.26.134.10:6050 shows as disabled and kamailio started to accept sip requests. How is it possible that one non-responding rtpengine can paralyze the whole sip proxy? -- Juha _______________________________________________ Kamailio (SER) - Users Mailing List sr-users(a)lists.kamailio.org https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users

* Paolo Visintin - evosip.cloud writes: an That would work for me too. Also starting with all rtpproxies disabled and then enabling them after start. Exactly, but all these are hacks. This is a VERY serious issue and needs to be properly fixed. -- Juha _______________________________________________ Kamailio (SER) - Users Mailing List sr-users(a)lists.kamailio.org https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users

Daniel-Constantin Mierla writes: Yes, UDP register is sent, but kamailio does not respond to it. Then I did this. 1) Started K where rtpengine udp:192.26.134.10:6050 is enabled but is not running. 2) Gave kamcmd command. It two about two minutes before I got the prompt. 3) Gave 'rtpengine.show all' command. It took perhaps 30 seconds to produce: { url: udp:127.0.0.1:6050 set: 0 index: 0 weight: 10 disabled: 0 recheck_ticks: 0 } { url: udp:192.26.134.10:6050 set: 0 index: 2 weight: 1 disabled: 1 recheck_ticks: 60 } { url: udp:192.26.134.10:6050 set: 1 index: 1 weight: 1 disabled: 1(permanent) recheck_ticks: N/A } Now udp:192.26.134.10:6050 shows as disabled and kamailio started to accept sip requests. How is it possible that one non-responding rtpengine can paralyze the whole sip proxy? -- Juha

Daniel-Constantin Mierla writes: Yes, I have two in one set: udp:127.0.0.1:6050 (running) udp:192.26.134.10:6050 (host 192.26.134.10 is down) top does not show any kamailio processes in the top. In addition to not responding to sip requests, kamailio does not respond to kamcmd command either. It stars to respond when rtpengine module gives up on trying and declares udp:192.26.134.10:6050 disabled. -- Juha

I was able to figure out what could be the cause with: modparam("rtpengine", "rtpengine_sock", "udp:127.0.0.1:2223 udp:192.168.64.4:2224")

You can make a fix yourself if you want and have the time. It is not a module I coded, nor the one that added db support for it, so I am also coding by learning what was done there.

Maybe you would also want to tune the timeout with the modparam: modparam("rtpengine", "rtpengine_disable_tout", 5) So detection of unavailable rtpproxy is fast, otherwise it is 60 sec by default, so you may still experience some slow start per child process.

I pushed a quick fix for the case when db support is not enabled, because these locks are useless in that case, so all children will do the rtpengine init at the same time, without waiting for the others:

I just pushed a series of commits trying to rework how loading (and reloading) of rtpegines list is done, to avoid that sync'ed probing, which can take long if any of the rtpengines is down.