26 Feb
2024
26 Feb
'24
7: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>