[kamailio/kamailio] ndb_reids module in event_route[tcp:closed] route block error: "no redis context for server" (Issue #3768)
26 Feb
2024
26 Feb
'24
12:53 a.m.
### Description
The process of using kamailio prompts the following error：
ERROR: ndb_redis [redis_client.c:963]: redisc_exec(): no redis context for server: srvN
I did not encounter similar errors in version 5.4.8, and there were no similar errors in
other routing blocks. Suspect that the new core version has unknown logical issues with
the routing block of the module in event_route.
<!--
Explain what you did, what you expected to happen, and what actually happened.
-->
#### Log Messages
<!--
Check the syslog file and if there are relevant log messages printed by Kamailio, add them
next, or attach to issue, or provide a link to download them (e.g., to a pastebin site).
-->
```
2024-02-26T03:39:11.161557654Z 51(97) DEBUG: <core> [core/tcp_read.c:280]:
tcp_read_data(): EOF on connection 0x7f24539006a0 (state: 0, flags: c018) - FD 24, bytes
0, rd-flags 10000 ([12.0.1.6]:22827 -> [12.0.1.6]:5060)51(97) DEBUG: <core>
[core/tcp_read.c:343]: tcp_read(): read 0 bytes:
2024-02-26T03:39:11.161563494Z
2024-02-26T03:39:11.161567864Z 51(97) DEBUG: <core> [core/tcp_read.c:1532]:
tcp_read_req(): read= 0 bytes, parsed=0, state=0, error=1
2024-02-26T03:39:11.161574144Z 51(97) DEBUG: <core> [core/tcp_read.c:1534]:
tcp_read_req(): last char=0x00, parsed msg=
2024-02-26T03:39:11.161579134Z
2024-02-26T03:39:11.161584594Z 51(97) DEBUG: <core> [core/tcp_read.c:1544]:
tcp_read_req(): EOF
2024-02-26T03:39:11.161598914Z 51(97) DEBUG: <core> [core/io_wait.h:598]:
io_watch_del(): DBG: io_watch_del (0x563e1ce29740, 24, -1, 0x10) fd_no=2 called
2024-02-26T03:39:11.161604494Z 51(97) DEBUG: <core> [core/tcp_read.c:1927]:
handle_io(): removing from list 0x7f24539006a0 id 1 fd 24, state 2, flags c018, main fd
132, refcnt 2 ([12.0.1.6]:22827 -> [12.0.1.6]:5060)
2024-02-26T03:39:11.161610294Z 51(97) DEBUG: <core> [core/tcp_read.c:1702]:
release_tcpconn(): releasing con 0x7f24539006a0, state -1, fd=24, id=1 ([12.0.1.6]:22827
-> [12.0.1.6]:5060)
2024-02-26T03:39:11.161615934Z 51(97) DEBUG: <core> [core/tcp_read.c:1705]:
release_tcpconn(): extra_data (nil)
2024-02-26T03:39:11.162263374Z 83(129) DEBUG: <core> [core/tcp_main.c:3747]:
handle_tcp_child(): reader response= 7f24539006a0, -1 from 0
2024-02-26T03:39:11.162286594Z 83(129) DEBUG: <core> [core/tcp_main.c:3671]:
tcp_emit_closed_event(): TCP closed event creation triggered (reason: 0)
2024-02-26T03:39:11.162293034Z 83(129) DEBUG: tcpops [tcpops.c:311]:
tcpops_handle_tcp_closed(): received TCP closed event
2024-02-26T03:39:11.162299134Z 83(129) DEBUG: tcpops [tcpops.c:261]:
tcpops_tcp_closed_run_route(): event reason id: 0 rt: 1
2024-02-26T03:39:11.162304234Z 83(129) ERROR: tcpops [tcpops.c:278]:
tcpops_tcp_closed_run_route(): run_top_route() before tev->id: 1
2024-02-26T03:39:11.162311444Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]:
_tcpconn_find(): 1 port 0
2024-02-26T03:39:11.162316784Z 83(129) DEBUG: <core> [core/tcp_main.c:1721]:
_tcpconn_find(): c=0x7f24539006a0, c->id=1, port=22827
2024-02-26T03:39:11.162322944Z 83(129) DEBUG: <core> [core/ip_addr.c:577]:
print_ip(): ip=12.0.1.6
2024-02-26T03:39:11.162328584Z 83(129) DEBUG: <core> [core/tcp_main.c:1725]:
_tcpconn_find(): found connection by id: 1
2024-02-26T03:39:11.162333764Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]:
_tcpconn_find(): 1 port 0
2024-02-26T03:39:11.162338674Z 83(129) DEBUG: <core> [core/tcp_main.c:1721]:
_tcpconn_find(): c=0x7f24539006a0, c->id=1, port=22827
2024-02-26T03:39:11.162343764Z 83(129) DEBUG: <core> [core/ip_addr.c:577]:
print_ip(): ip=12.0.1.6
2024-02-26T03:39:11.162349254Z 83(129) DEBUG: <core> [core/tcp_main.c:1725]:
_tcpconn_find(): found connection by id: 1
2024-02-26T03:39:11.162355494Z 83(129) DEBUG: <core> [core/pvapi.c:1418]:
pv_printf_mode(): final buffer length 101
2024-02-26T03:39:11.162360924Z 83(129) ERROR: <script>: tcp connection closed conid:
(1), tcp(conid): 1, Ri: 12.0.1.185, Rp: 5060 , si: 12.0.1.6 , sp: 22827
2024-02-26T03:39:11.162375744Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]:
_tcpconn_find(): 1 port 0
2024-02-26T03:39:11.162381944Z 83(129) DEBUG: <core> [core/tcp_main.c:1721]:
_tcpconn_find(): c=0x7f24539006a0, c->id=1, port=22827
2024-02-26T03:39:11.162388024Z 83(129) DEBUG: <core> [core/ip_addr.c:577]:
print_ip(): ip=12.0.1.6
2024-02-26T03:39:11.162395164Z 83(129) DEBUG: <core> [core/tcp_main.c:1725]:
_tcpconn_find(): found connection by id: 1
2024-02-26T03:39:11.162400884Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]:
_tcpconn_find(): 1 port 0
2024-02-26T03:39:11.162406634Z 83(129) DEBUG: <core> [core/tcp_main.c:1721]:
_tcpconn_find(): c=0x7f24539006a0, c->id=1, port=22827
2024-02-26T03:39:11.162412284Z 83(129) DEBUG: <core> [core/ip_addr.c:577]:
print_ip(): ip=12.0.1.6
2024-02-26T03:39:11.162417034Z 83(129) DEBUG: <core> [core/tcp_main.c:1725]:
_tcpconn_find(): found connection by id: 1
2024-02-26T03:39:11.162422294Z 83(129) DEBUG: <core> [core/pvapi.c:1418]:
pv_printf_mode(): final buffer length 27
2024-02-26T03:39:11.162427844Z 83(129) ERROR: <script>: tcp connection closed (1)
2024-02-26T03:39:11.162433574Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]:
_tcpconn_find(): 1 port 0
2024-02-26T03:39:11.162439254Z 83(129) DEBUG: <core> [core/tcp_main.c:1721]:
_tcpconn_find(): c=0x7f24539006a0, c->id=1, port=22827
2024-02-26T03:39:11.162444184Z 83(129) DEBUG: <core> [core/ip_addr.c:577]:
print_ip(): ip=12.0.1.6
2024-02-26T03:39:11.162449324Z 83(129) DEBUG: <core> [core/tcp_main.c:1725]:
_tcpconn_find(): found connection by id: 1
2024-02-26T03:39:11.162454724Z 83(129) DEBUG: <core> [core/pvapi.c:1418]:
pv_printf_mode(): final buffer length 1
2024-02-26T03:39:11.162460094Z 83(129) DEBUG: <core> [core/pvapi.c:1418]:
pv_printf_mode(): final buffer length 52
2024-02-26T03:39:11.162466084Z 83(129) DEBUG: <core> [core/tcp_main.c:1713]:
_tcpconn_find(): 1 port 0
2024-02-26T03:39:11.162471724Z 83(129) DEBUG: <core> [core/tcp_main.c:1721]:
_tcpconn_find(): c=0x7f24539006a0, c->id=1, port=22827
2024-02-26T03:39:11.162477324Z 83(129) DEBUG: <core> [core/ip_addr.c:577]:
print_ip(): ip=12.0.1.6
2024-02-26T03:39:11.162482144Z 83(129) DEBUG: <core> [core/tcp_main.c:1725]:
_tcpconn_find(): found connection by id: 1
2024-02-26T03:39:11.162487154Z 83(129) DEBUG: <core> [core/pvapi.c:1418]:
pv_printf_mode(): final buffer length 52
2024-02-26T03:39:11.162501164Z 83(129) DEBUG: ndb_redis [redis_client.c:399]:
redisc_get_server(): Hash 2100282857 (srvN)
2024-02-26T03:39:11.162508124Z 83(129) DEBUG: ndb_redis [redis_client.c:402]:
redisc_get_server(): Entry 2694209461 (12.0.1.9:7469), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162514104Z 83(129) DEBUG: ndb_redis [redis_client.c:402]:
redisc_get_server(): Entry 2694209462 (12.0.1.8:7469), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162520554Z 83(129) DEBUG: ndb_redis [redis_client.c:402]:
redisc_get_server(): Entry 2694209448 (12.0.1.7:7469), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162526404Z 83(129) DEBUG: ndb_redis [redis_client.c:402]:
redisc_get_server(): Entry 2694210133 (12.0.1.9:7369), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162532034Z 83(129) DEBUG: ndb_redis [redis_client.c:402]:
redisc_get_server(): Entry 2694210134 (12.0.1.8:7369), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162537324Z 83(129) DEBUG: ndb_redis [redis_client.c:402]:
redisc_get_server(): Entry 2694210120 (12.0.1.7:7369), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162542824Z 83(129) DEBUG: ndb_redis [redis_client.c:402]:
redisc_get_server(): Entry 2100282854 (srvM), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162548064Z 83(129) DEBUG: ndb_redis [redis_client.c:402]:
redisc_get_server(): Entry 2100282857 (srvN), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162554074Z 83(129) DEBUG: ndb_redis [redis_client.c:402]:
redisc_get_server(): Entry 2100306023 (srvTPS), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162559184Z 83(129) DEBUG: ndb_redis [redis_client.c:408]:
redisc_get_server(): Entry 2694209461 (12.0.1.9:7469), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162564524Z 83(129) DEBUG: ndb_redis [redis_client.c:408]:
redisc_get_server(): Entry 2694209462 (12.0.1.8:7469), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162569904Z 83(129) DEBUG: ndb_redis [redis_client.c:408]:
redisc_get_server(): Entry 2694209448 (12.0.1.7:7469), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162575334Z 83(129) DEBUG: ndb_redis [redis_client.c:408]:
redisc_get_server(): Entry 2694210133 (12.0.1.9:7369), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162580154Z 83(129) DEBUG: ndb_redis [redis_client.c:408]:
redisc_get_server(): Entry 2694210134 (12.0.1.8:7369), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162585964Z 83(129) DEBUG: ndb_redis [redis_client.c:408]:
redisc_get_server(): Entry 2694210120 (12.0.1.7:7369), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162592294Z 83(129) DEBUG: ndb_redis [redis_client.c:408]:
redisc_get_server(): Entry 2100282854 (srvM), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162597644Z 83(129) DEBUG: ndb_redis [redis_client.c:408]:
redisc_get_server(): Entry 2100282857 (srvN), rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162611324Z 83(129) DEBUG: ndb_redis [redis_client.c:413]:
redisc_get_server(): Using entry 2100282857 (srvN)
2024-02-26T03:39:11.162617084Z 83(129) DEBUG: ndb_redis [redis_client.c:960]:
redisc_exec(): rsrv->ctxRedis = (nil)
2024-02-26T03:39:11.162622004Z 83(129) ERROR: ndb_redis [redis_client.c:963]:
redisc_exec(): no redis context for server: srvN
2024-02-26T03:39:11.162627834Z 83(129) ERROR: tcpops [tcpops.c:280]:
tcpops_tcp_closed_run_route(): run_top_route() after tev->id: 1
2024-02-26T03:39:11.162633294Z 83(129) DEBUG: <core> [core/tcp_main.c:3904]:
handle_tcp_child(): case CONN_EOF tcp_emit_closed_event before 5
```
#### SIP Traffic
<!--
If the issue is exposed by processing specific SIP messages, grab them with ngrep or save
in a pcap file, then add them next, or attach to issue, or provide a link to download them
(e.g., to a pastebin site).
-->
```
event_route[tcp:closed] {
xlog("L_ERR", "$proto connection closed conid: ($conid),
tcp(conid): $tcp(conid), Ri: $Ri, Rp: $Rp , si: $si , sp: $sp\n");
if($conid ne $null) {
xlog("L_ERR", "$proto connection closed
($conid)\n");
route(TCPEVENT);
}
}
route[TCPEVENT] {
if(redis_cmd("srvN", "get %s", "$conid",
"r")) {
.....
}
}
#redis module config
loadmodule "ndb_redis"
modparam("ndb_redis", "cluster", 1)
modparam("ndb_redis", "allow_dynamic_nodes", 1)
modparam("ndb_redis", "server",
"name=srvN;addr=NDB_N_REDIS_CLUSTER_MAINADDR;port=NDB_N_REDIS_CLUSTER_MAINPORT;pass=NDB_REDIS_PASSWORD")
modparam("ndb_redis", "server",
"name=srvM;addr=NDB_M_REDIS_CLUSTER_MAINADDR;port=NDB_M_REDIS_CLUSTER_MAINPORT;pass=NDB_REDIS_PASSWORD")
modparam("ndb_redis", "server",
"name=12.0.1.7:7369;addr=12.0.1.7;port=7369;pass=NDB_REDIS_PASSWORD")
modparam("ndb_redis", "server",
"name=12.0.1.8:7369;addr=12.0.1.8;port=7369;pass=NDB_REDIS_PASSWORD")
modparam("ndb_redis", "server",
"name=12.0.1.9:7369;addr=12.0.1.9;port=7369;pass=NDB_REDIS_PASSWORD")
modparam("ndb_redis", "server",
"name=12.0.1.7:7469;addr=12.0.1.7;port=7469;pass=NDB_REDIS_PASSWORD")
modparam("ndb_redis", "server",
"name=12.0.1.8:7469;addr=12.0.1.8;port=7469;pass=NDB_REDIS_PASSWORD")
modparam("ndb_redis", "server",
"name=12.0.1.9:7469;addr=12.0.1.9;port=7469;pass=NDB_REDIS_PASSWORD")
```
* **Operating System**:
<!--
Details about the operating system, the type: Linux (e.g.,: Debian 8.4, Ubuntu 16.04,
CentOS 7.1, ...), MacOS, xBSD, Solaris, ...;
Kernel details (output of `lsb_release -a` and `uname -a`)
-->
```
version: kamailio 5.7.4 (x86_64/linux) 9920d9-dirty
flags: , EXTRA_DEBUGUSE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE,
USE_MCAST, DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, MEM_JOIN_FREE, 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: 9920d9 -dirty
compiled on 09:59:52 Feb 26 2024 with gcc 7.5.0
```
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3768
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issues/3768(a)github.com>
26 Feb
26 Feb
3:48 a.m.
My guess is that the event route is executed by tcp-main process and that one has never
had the connection to redis, as I looked at the code, it is like that since 2011 or so.
Probably what is newer is the log error message.
Therefore the question is whether it actually worked to use redis_cmd() in that event rate
(it did what it was supposed to do), or it was just no error log message, but the command
didn't work?
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3768#issuecomment-1963595956
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issues/3768/1963595956(a)github.com>
4:17 a.m.
Kamailio version 5.4.8 can be used normally. I have checked the logs and found that each
process successfully initialized the variable, and no other errors were found. I also did
not see any other normal business processes that set rsrv ->ctxRedis=NULL. All
processes are only released when the program exits. Also, I saw from netstat that all TCP
links are in an established state.
```
...
2024-02-26T06:51:05.272902281Z 77(123) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c1af0
2024-02-26T06:51:05.272906511Z 81(127) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.272919041Z 82(128) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c12b0
2024-02-26T06:51:05.272933851Z 78(124) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c4de0
2024-02-26T06:51:05.272963411Z 77(123) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.285328567Z 81(127) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2840
2024-02-26T06:51:05.285574157Z 82(128) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7469
2024-02-26T06:51:05.285588327Z 80(126) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.8:7369
2024-02-26T06:51:05.285595027Z 82(128) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c3d10
2024-02-26T06:51:05.285717157Z 81(127) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.285721697Z 82(128) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.9:7369
2024-02-26T06:51:05.285726187Z 78(124) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.8:7469
2024-02-26T06:51:05.285729947Z 82(128) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c3390
2024-02-26T06:51:05.285735627Z 81(127) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c4ad0
2024-02-26T06:51:05.285739987Z 80(126) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2b10
2024-02-26T06:51:05.285747267Z 75(121) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.8:7369
2024-02-26T06:51:05.285761797Z 82(128) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.8:7369
2024-02-26T06:51:05.285783837Z 82(128) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2b10
2024-02-26T06:51:05.285787687Z 82(128) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.285791427Z 82(128) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2e80
2024-02-26T06:51:05.285799057Z 82(128) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7469
2024-02-26T06:51:05.285806657Z 77(123) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2840
2024-02-26T06:51:05.285813597Z 82(128) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c1af0
2024-02-26T06:51:05.285817647Z 78(124) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c12b0
2024-02-26T06:51:05.285897427Z 82(128) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.285906537Z 82(128) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2840
2024-02-26T06:51:05.285911297Z 82(128) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.285917977Z 82(128) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c4ad0
2024-02-26T06:51:05.308957137Z 75(121) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2b10
2024-02-26T06:51:05.309168218Z 80(126) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.309183338Z 80(126) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2e80
2024-02-26T06:51:05.309187808Z 75(121) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.309192678Z 77(123) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.309198708Z 78(124) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7469
2024-02-26T06:51:05.309203128Z 77(123) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c4ad0
2024-02-26T06:51:05.309208338Z 75(121) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2e80
2024-02-26T06:51:05.309212358Z 78(124) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c3d10
2024-02-26T06:51:05.309329668Z 75(121) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7469
2024-02-26T06:51:05.309335838Z 75(121) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c1af0
2024-02-26T06:51:05.309339958Z 75(121) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.309345148Z 75(121) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2840
2024-02-26T06:51:05.309349318Z 75(121) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.309354228Z 75(121) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c4ad0
2024-02-26T06:51:05.309385778Z 80(126) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7469
2024-02-26T06:51:05.309390028Z 80(126) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c1af0
2024-02-26T06:51:05.309395598Z 80(126) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.309416238Z 80(126) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2840
2024-02-26T06:51:05.309421298Z 80(126) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.309425378Z 80(126) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c4ad0
2024-02-26T06:51:05.309442258Z 78(124) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.9:7369
2024-02-26T06:51:05.320999073Z 78(124) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c3390
2024-02-26T06:51:05.332643058Z 78(124) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.8:7369
2024-02-26T06:51:05.336555480Z 78(124) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2b10
2024-02-26T06:51:05.337678340Z 78(124) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.345606164Z 78(124) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2e80
2024-02-26T06:51:05.345698304Z 78(124) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7469
2024-02-26T06:51:05.345709604Z 78(124) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c1af0
2024-02-26T06:51:05.345714844Z 78(124) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.345719144Z 78(124) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2840
2024-02-26T06:51:05.345723774Z 78(124) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.345791794Z 78(124) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c4ad0
2024-02-26T06:51:05.408166382Z 1(47) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.9:7469
2024-02-26T06:51:05.408690623Z 1(47) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c4de0
2024-02-26T06:51:05.409249123Z 1(47) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.8:7469
2024-02-26T06:51:05.409404343Z 1(47) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c12b0
2024-02-26T06:51:05.409708683Z 1(47) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7469
2024-02-26T06:51:05.409854203Z 1(47) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c3d10
2024-02-26T06:51:05.410137103Z 1(47) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.9:7369
2024-02-26T06:51:05.410291773Z 1(47) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c3390
2024-02-26T06:51:05.410691894Z 1(47) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.8:7369
2024-02-26T06:51:05.410901694Z 1(47) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2b10
2024-02-26T06:51:05.411303174Z 1(47) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.411450584Z 1(47) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2e80
2024-02-26T06:51:05.411740424Z 1(47) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7469
2024-02-26T06:51:05.411870844Z 1(47) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c1af0
2024-02-26T06:51:05.412134044Z 1(47) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.412336694Z 1(47) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c2840
2024-02-26T06:51:05.412625645Z 1(47) DEBUG: ndb_redis [redis_client.c:227]:
redisc_init(): Connecting to 12.0.1.7:7369
2024-02-26T06:51:05.412802495Z 1(47) DEBUG: ndb_redis [redis_client.c:231]:
redisc_init(): rsrv->ctxRedis = 0x5613031c4a
...
...
netstat -anp|grep 7369
result:
tcp 0 0 12.0.1.185:43654 12.0.1.7:7369 ESTABLISHED
233801/kamailio
tcp 0 0 12.0.1.185:44398 12.0.1.7:7369 ESTABLISHED
233834/kamailio
tcp 0 0 12.0.1.185:45222 12.0.1.7:7369 ESTABLISHED
233861/kamailio
tcp 0 0 12.0.1.185:55608 12.0.1.9:7369 ESTABLISHED
233804/kamailio
tcp 0 0 12.0.1.185:43972 12.0.1.7:7369 ESTABLISHED
233816/kamailio
tcp 0 0 12.0.1.185:45162 12.0.1.7:7369 ESTABLISHED
233860/kamailio
tcp 0 0 12.0.1.185:44838 12.0.1.7:7369 ESTABLISHED
233851/kamailio
tcp 0 0 12.0.1.185:45186 12.0.1.8:7369 ESTABLISHED
233838/kamailio
tcp 0 0 12.0.1.185:56020 12.0.1.9:7369 ESTABLISHED
233846/kamailio
tcp 0 0 12.0.1.185:44000 12.0.1.7:7369 ESTABLISHED
233812/kamailio
tcp 0 0 12.0.1.185:55894 12.0.1.9:7369 ESTABLISHED
233836/kamailio
tcp 0 0 12.0.1.185:55834 12.0.1.9:7369 ESTABLISHED
233831/kamailio
tcp 0 0 12.0.1.185:44626 12.0.1.7:7369 ESTABLISHED
233837/kamailio
tcp 0 0 12.0.1.185:44886 12.0.1.7:7369 ESTABLISHED
233845/kamailio
tcp 0 0 12.0.1.185:44896 12.0.1.8:7369 ESTABLISHED
233812/kamailio
tcp 0 0 12.0.1.185:44254 12.0.1.7:7369 ESTABLISHED
233831/kamailio
tcp 0 0 12.0.1.185:56178 12.0.1.9:7369 ESTABLISHED
233866/kamailio
tcp 0 0 12.0.1.185:45478 12.0.1.7:7369 ESTABLISHED
233864/kamailio
tcp 0 0 12.0.1.185:44012 12.0.1.7:7369 ESTABLISHED
233818/kamailio
tcp 0 0 12.0.1.185:44648 12.0.1.7:7369 ESTABLISHED
233834/kamailio
tcp 0 0 12.0.1.185:44700 12.0.1.7:7369 ESTABLISHED
233842/kamailio
tcp 0 0 12.0.1.185:55698 12.0.1.9:7369 ESTABLISHED
233812/kamailio
tcp 0 0 12.0.1.185:55842 12.0.1.9:7369 ESTABLISHED
233833/kamailio
tcp 0 0 12.0.1.185:44712 12.0.1.7:7369 ESTABLISHED
233840/kamailio
tcp 0 0 12.0.1.185:45258 12.0.1.8:7369 ESTABLISHED
233858/kamailio
tcp 0 0 12.0.1.185:56038 12.0.1.9:7369 ESTABLISHED
233851/kamailio
tcp 0 0 12.0.1.185:56218 12.0.1.9:7369 ESTABLISHED
233871/kamailio
tcp 0 0 12.0.1.185:43886 12.0.1.7:7369 ESTABLISHED
233807/kamailio
tcp 0 0 12.0.1.185:43576 12.0.1.7:7369 ESTABLISHED
233798/kamailio
tcp 0 0 12.0.1.185:44292 12.0.1.7:7369 ESTABLISHED
233820/kamailio
tcp 0 0 12.0.1.185:55986 12.0.1.9:7369 ESTABLISHED
233843/kamailio
tcp 0 0 12.0.1.185:44964 12.0.1.8:7369 ESTABLISHED
233817/kamailio
tcp 0 0 12.0.1.185:44894 12.0.1.7:7369 ESTABLISHED
233848/kamailio
tcp 0 0 12.0.1.185:44706 12.0.1.8:7369 ESTABLISHED
233792/kamailio
tcp 0 0 12.0.1.185:44106 12.0.1.7:7369 ESTABLISHED
233824/kamailio
tcp 0 0 12.0.1.185:44370 12.0.1.7:7369 ESTABLISHED
233837/kamailio
tcp 0 0 12.0.1.185:45224 12.0.1.8:7369 ESTABLISHED
233845/kamailio
tcp 0 0 12.0.1.185:45356 12.0.1.8:7369 ESTABLISHED
233860/kamailio
tcp 0 0 12.0.1.185:44334 12.0.1.7:7369 ESTABLISHED
233833/kamailio
tcp 0 0 12.0.1.185:45508 12.0.1.7:7369 ESTABLISHED
233867/kamailio
....
```
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3768#issuecomment-1963646836
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issues/3768/1963646836(a)github.com>
4:46 a.m.
Can you also provide the output of "kamctl ps" for the same instance from where
you get the logs?
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3768#issuecomment-1963704189
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issues/3768/1963704189(a)github.com>
4:58 a.m.
I suspect that there may be compatibility issues between the new version of the TCP model
and the old ndd_redis module during module initialization. I suspect that the processing
logic triggered by this event occurred in the main process, which did not initialize the
relevant context. I have attempted to modify the following code：
···
file:ndb_redis/ndb_redis_mod.c
151 if(rank == PROC_INIT || rank == PROC_MAIN || rank == PROC_TCP_MAIN)
modify:
151 if(rank == PROC_INIT || rank == PROC_MAIN )
···
Based on the above tests, it can be basically determined that the event_route event was
triggered in the TCP main process, rather than in the expected child process, which is
also the reason why it cannot obtain the context normally. I'm not sure if this
handling is reasonable and won't cause any other problems, but it can indeed run
normally. Is there any other better way? I speculate that the related issues should be
quite common, whether it is better to solve them from the framework level rather than the
module itself. And all operations are handled by the main process, and its performance is
also worrying.
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3768#issuecomment-1963728833
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issues/3768/1963728833(a)github.com>
7:07 a.m.
That's exactly the code I looked at and said that is there from like 2011, therefore
questioning if it really worked differently in 5.4.x vs 5.7.x. The log message might not
have been there, but the condition was. If I haven't missed any related commit, it is
no major difference in the internal TCP design between 5.4 and 5.7.
Anyhow, I will commit an update to initialise the ndb context for tcp-main and look to
see if it is needed for the main attendant as well.
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3768#issuecomment-1963993740
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issues/3768/1963993740(a)github.com>
8:08 a.m.
I pushed a commit to git master branch, can you try with it and see if works as expected?
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3768#issuecomment-1964108110
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issues/3768/1964108110(a)github.com>
27 Feb
27 Feb
6:22 a.m.
hi，After my testing, the new modifications ran smoothly and the results met expectations.
However, during the testing process, I discovered a new issue where I was unable to obtain
$conid in the event_route [tcp: timeout] routing block. After analyzing, it was found that
the find_conn method in the tcp_main. c file returned directly when it determined that the
status of conn was BAD, and the relevant connection information was not successfully
obtained. Given the relative proofreading of this issue, I will attempt to use the
relevant logic from version 5.4.8 to rollback, mainly by removing the
tcp_mait_closed_event call from the tcp_main. c file and adding this function call to the
relevant code in tcp_read. c. After modification and testing, all issues disappeared, and
the desired parameters could be obtained and executed normally within each close event.
After observation, the relevant code should be executed in the child process, which does
not have any impact on the main process. I think it is more reasonable. All the related
functions of the new version have been placed in the main process for global management.
The advantage is that the management is convenient and there will be no omissions.
However, the disadvantage is that the main process does too much, and all the objects in
the child processes need to have copies in the main process to be called normally. The
main process is too cumbersome, and I don't think it's a good design. I
haven't thought of a better solution for this while, The occupancy time can only be
reverted back to the old version mode, which is currently more practical.
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3768#issuecomment-1966333394
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issues/3768/1966333394(a)github.com>
28 Feb
28 Feb
11:35 a.m.
The tcp_read.c code does not cover all cases when the connection can be closed, only when
that happens during reading operations. But not on lifetime expiration and some other
events -- that was the reason to move the execution of the event route for closed event in
the tcp-main, because it is the process that destroys it, even when the close is detected
on-read.
I don't think the solution is to go back to the older approach, but find a way to
share the connection structure, because it is not yet destroyed when event route is
executed, just no longer in the hash table.
Btw, I pushed some code after my previous comment, trying to make it more flexible to work
with both cases: connection found active or connection just available for the event_route
before destroying it.
Regarding the fact that the main-tcp can be occupied too long, that is a matter of what
you do in the event route. If you know that is going to be some lengthly action with
network i/o, then delegate it to another worker with mqueue+rtimer or async modules.
Similar problems can happen for lengthy actions used in failure-route (blocking timer
process) or even for sip worker processes.
Anyhow, you are welcome to propose enhancements as PRs, they will be reviewed and merged
if they improve things.
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3768#issuecomment-1969380889
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issues/3768/1969380889(a)github.com>
10 Apr
10 Apr
10:38 p.m.
This issue is stale because it has been open 6 weeks with no activity. Remove stale label
or comment or this will be closed in 2 weeks.
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3768#issuecomment-2048833958
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issues/3768/2048833958(a)github.com>
24 Apr
24 Apr
10:39 p.m.
Closed #3768 as not planned.
--
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3768#event-12600481428
You are receiving this because you are subscribed to this thread.
Message ID: <kamailio/kamailio/issue/3768/issue_event/12600481428(a)github.com>
297
days inactive
356
days old
10 comments
3 participants
participants (3)
-
Daniel-Constantin Mierla -
github-actions[bot]
-
liangbaolin