9 Oct
2022
9 Oct
'22
5:25 p.m.
I am running latest kamailio 5.6.2 and attempting to detect tcp/tls connection being
disconnected or closed using tcpops module. As suggested in tcpops documentation at
https://www.kamailio.org/docs/modules/devel/modules/tcpops.html, registered event routes
as below.
event_route[tcp:closed] {
xlog("L_INFO", "$proto connection closed ($conid)\n");
}
event_route[tcp:timeout] {
xlog("L_INFO", "$proto connection timed out ($conid)\n");
}
event_route[tcp:reset] {
xlog("L_INFO", "$proto connection reset by peer ($conid)\n");
}
Now it is observed that the event route is being called but the $conid is not set. The
logs show the below log statements and extra data is (nil).
24(4263) DEBUG: <core> [core/tcp_read.c:284]: tcp_read_data(): EOF on connection
0x7ffff2ff8b90 (state: 0, flags: 4018) - FD 7, bytes 0, rd-flags 10000
([10.8.137.33]:51069 -> [10.8.137.33]:5060)24(4263) DEBUG: <core>
[core/tcp_read.c:1500]: tcp_read_req(): EOF
24(4263) DEBUG: <core> [core/io_wait.h:600]: io_watch_del(): DBG: io_watch_del
(0x555555ab6960, 7, -1, 0x10) fd_no=2 called
24(4263) DEBUG: <core> [core/tcp_read.c:1870]: handle_io(): removing from list
0x7ffff2ff8b90 id 1 fd 7, state 2, flags 4018, main fd 51, refcnt 2 ([10.8.137.33]:51069
-> [10.8.137.33]:5060)
24(4263) DEBUG: <core> [core/tcp_read.c:1653]: release_tcpconn(): releasing con
0x7ffff2ff8b90, state -1, fd=7, id=1 ([10.8.137.33]:51069 -> [10.8.137.33]:5060)
24(4263) DEBUG: <core> [core/tcp_read.c:1657]: release_tcpconn(): extra_data (nil)
32(4271) DEBUG: <core> [core/tcp_main.c:3651]: handle_tcp_child(): reader response=
7ffff2ff8b90, -1 from 0
32(4271) DEBUG: <core> [core/tcp_main.c:3576]: tcp_emit_closed_event(): TCP closed
event creation triggered (reason: 0)
32(4271) DEBUG: tcpops [tcpops.c:295]: tcpops_handle_tcp_closed(): received TCP closed
event
32(4271) DEBUG: tcpops [tcpops.c:249]: tcpops_tcp_closed_run_route(): event reason id: 0
rt: 1
32(4271) DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line(): first
line type 1 (request) flags 1
32(4271) DEBUG: <core> [core/parser/msg_parser.c:679]: parse_msg(): SIP Request:
32(4271) DEBUG: <core> [core/parser/msg_parser.c:681]: parse_msg(): method:
<OPTIONS>
32(4271) DEBUG: <core> [core/parser/msg_parser.c:683]: parse_msg(): uri:
<sip:you@kamailio.org>
32(4271) DEBUG: <core> [core/parser/msg_parser.c:685]: parse_msg(): version:
<SIP/2.0>
32(4271) DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name():
parsed header name [Via] type 1
32(4271) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header
reached, state=2
32(4271) DEBUG: <core> [core/parser/msg_parser.c:555]: parse_headers(): Via found,
flags=2
32(4271) DEBUG: <core> [core/parser/msg_parser.c:557]: parse_headers(): this is the
first via
32(4271) exec: *** cfgtrace:dbg_cfg_trace(): unknown_route=[tcp:closed]
c=[/usr/local/etc/kamailio/kamailio.cfg] l=976 a=26 n=xlog32(4271) INFO: <script>
tcp connection closed (<null>)
Can anyone provide any pointers on what I am missing?
Thanks in advance.
9 Oct
9 Oct
6:25 p.m.
Looking at the source code, it seems the extra_data is not set. But that does not explain
why $conid is <null> when tcp:closed event route is triggered.
------- Original Message -------
On Sunday, October 9th, 2022 at 19:55, sthustfo <sthustfo(a)proton.me> wrote:
I am running latest kamailio 5.6.2 and attempting to
detect tcp/tls connection being disconnected or closed using tcpops module. As suggested
in tcpops documentation at
https://www.kamailio.org/docs/modules/devel/modules/tcpops.html, registered event routes
as below.
event_route[tcp:closed] {
xlog("L_INFO", "$proto connection closed ($conid)\n");
}
event_route[tcp:timeout] {
xlog("L_INFO", "$proto connection timed out ($conid)\n");
}
event_route[tcp:reset] {
xlog("L_INFO", "$proto connection reset by peer ($conid)\n");
}
Now it is observed that the event route is being called but the $conid is not set. The
logs show the below log statements and extra data is (nil).
24(4263) DEBUG: <core> [core/tcp_read.c:284]: tcp_read_data(): EOF on connection
0x7ffff2ff8b90 (state: 0, flags: 4018) - FD 7, bytes 0, rd-flags 10000
([10.8.137.33]:51069 -> [10.8.137.33]:5060)24(4263) DEBUG: <core>
[core/tcp_read.c:1500]: tcp_read_req(): EOF
24(4263) DEBUG: <core> [core/io_wait.h:600]: io_watch_del(): DBG: io_watch_del
(0x555555ab6960, 7, -1, 0x10) fd_no=2 called
24(4263) DEBUG: <core> [core/tcp_read.c:1870]: handle_io(): removing from list
0x7ffff2ff8b90 id 1 fd 7, state 2, flags 4018, main fd 51, refcnt 2 ([10.8.137.33]:51069
-> [10.8.137.33]:5060)
24(4263) DEBUG: <core> [core/tcp_read.c:1653]: release_tcpconn(): releasing con
0x7ffff2ff8b90, state -1, fd=7, id=1 ([10.8.137.33]:51069 -> [10.8.137.33]:5060)
24(4263) DEBUG: <core> [core/tcp_read.c:1657]: release_tcpconn(): extra_data (nil)
32(4271) DEBUG: <core> [core/tcp_main.c:3651]: handle_tcp_child(): reader response=
7ffff2ff8b90, -1 from 0
32(4271) DEBUG: <core> [core/tcp_main.c:3576]: tcp_emit_closed_event(): TCP closed
event creation triggered (reason: 0)
32(4271) DEBUG: tcpops [tcpops.c:295]: tcpops_handle_tcp_closed(): received TCP closed
event
32(4271) DEBUG: tcpops [tcpops.c:249]: tcpops_tcp_closed_run_route(): event reason id: 0
rt: 1
32(4271) DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line(): first
line type 1 (request) flags 1
32(4271) DEBUG: <core> [core/parser/msg_parser.c:679]: parse_msg(): SIP Request:
32(4271) DEBUG: <core> [core/parser/msg_parser.c:681]: parse_msg(): method:
<OPTIONS>
32(4271) DEBUG: <core> [core/parser/msg_parser.c:683]: parse_msg(): uri:
<sip:you@kamailio.org>
32(4271) DEBUG: <core> [core/parser/msg_parser.c:685]: parse_msg(): version:
<SIP/2.0>
32(4271) DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name():
parsed header name [Via] type 1
32(4271) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header
reached, state=2
32(4271) DEBUG: <core> [core/parser/msg_parser.c:555]: parse_headers(): Via found,
flags=2
32(4271) DEBUG: <core> [core/parser/msg_parser.c:557]: parse_headers(): this is the
first via
32(4271) exec: *** cfgtrace:dbg_cfg_trace(): unknown_route=[tcp:closed]
c=[/usr/local/etc/kamailio/kamailio.cfg] l=976 a=26 n=xlog32(4271) INFO: <script>
tcp connection closed (<null>)
Can anyone provide any pointers on what I am missing?
Thanks in advance.
11 Oct
11 Oct
5:49 a.m.
Any pointers on what I am missing would be highly appreciated. The event routes are being
called but the $conid does not contain the proper value.
------- Original Message -------
On Sunday, October 9th, 2022 at 20:55, sthustfo <sthustfo(a)proton.me> wrote:
Looking at the source code, it seems the extra_data is
not set. But that does not explain why $conid is <null> when tcp:closed event route
is triggered.
------- Original Message -------
On Sunday, October 9th, 2022 at 19:55, sthustfo <sthustfo(a)proton.me> wrote:
> I am running latest kamailio 5.6.2 and attempting to detect tcp/tls connection being
disconnected or closed using tcpops module. As suggested in tcpops documentation at
https://www.kamailio.org/docs/modules/devel/modules/tcpops.html, registered event routes
as below.
>
> event_route[tcp:closed] {
> xlog("L_INFO", "$proto connection closed ($conid)\n");
> }
>
> event_route[tcp:timeout] {
> xlog("L_INFO", "$proto connection timed out ($conid)\n");
> }
>
> event_route[tcp:reset] {
> xlog("L_INFO", "$proto connection reset by peer ($conid)\n");
> }
>
> Now it is observed that the event route is being called but the $conid is not set.
The logs show the below log statements and extra data is (nil).
>
> 24(4263) DEBUG: <core> [core/tcp_read.c:284]: tcp_read_data(): EOF on
connection 0x7ffff2ff8b90 (state: 0, flags: 4018) - FD 7, bytes 0, rd-flags 10000
([10.8.137.33]:51069 -> [10.8.137.33]:5060)24(4263) DEBUG: <core>
[core/tcp_read.c:1500]: tcp_read_req(): EOF
> 24(4263) DEBUG: <core> [core/io_wait.h:600]: io_watch_del(): DBG: io_watch_del
(0x555555ab6960, 7, -1, 0x10) fd_no=2 called
> 24(4263) DEBUG: <core> [core/tcp_read.c:1870]: handle_io(): removing from list
0x7ffff2ff8b90 id 1 fd 7, state 2, flags 4018, main fd 51, refcnt 2 ([10.8.137.33]:51069
-> [10.8.137.33]:5060)
> 24(4263) DEBUG: <core> [core/tcp_read.c:1653]: release_tcpconn(): releasing con
0x7ffff2ff8b90, state -1, fd=7, id=1 ([10.8.137.33]:51069 -> [10.8.137.33]:5060)
> 24(4263) DEBUG: <core> [core/tcp_read.c:1657]: release_tcpconn(): extra_data
(nil)
> 32(4271) DEBUG: <core> [core/tcp_main.c:3651]: handle_tcp_child(): reader
response= 7ffff2ff8b90, -1 from 0
> 32(4271) DEBUG: <core> [core/tcp_main.c:3576]: tcp_emit_closed_event(): TCP
closed event creation triggered (reason: 0)
> 32(4271) DEBUG: tcpops [tcpops.c:295]: tcpops_handle_tcp_closed(): received TCP
closed event
> 32(4271) DEBUG: tcpops [tcpops.c:249]: tcpops_tcp_closed_run_route(): event reason
id: 0 rt: 1
> 32(4271) DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line():
first line type 1 (request) flags 1
> 32(4271) DEBUG: <core> [core/parser/msg_parser.c:679]: parse_msg(): SIP
Request:
> 32(4271) DEBUG: <core> [core/parser/msg_parser.c:681]: parse_msg(): method:
<OPTIONS>
> 32(4271) DEBUG: <core> [core/parser/msg_parser.c:683]: parse_msg(): uri:
<sip:you@kamailio.org>
> 32(4271) DEBUG: <core> [core/parser/msg_parser.c:685]: parse_msg(): version:
<SIP/2.0>
> 32(4271) DEBUG: <core> [core/parser/parse_hname2.c:301]:
parse_sip_header_name(): parsed header name [Via] type 1
> 32(4271) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of
header reached, state=2
> 32(4271) DEBUG: <core> [core/parser/msg_parser.c:555]: parse_headers(): Via
found, flags=2
> 32(4271) DEBUG: <core> [core/parser/msg_parser.c:557]: parse_headers(): this is
the first via
> 32(4271) exec: *** cfgtrace:dbg_cfg_trace(): unknown_route=[tcp:closed]
c=[/usr/local/etc/kamailio/kamailio.cfg] l=976 a=26 n=xlog32(4271) INFO: <script>
tcp connection closed (<null>)
>
> Can anyone provide any pointers on what I am missing?
>
> Thanks in advance.
9:29 a.m.
Hello,
did not looked into the code yet, but it might be just a bug/limitation of the module. You
could open an issue on our github tracker about it.
Cheers,
Henning
--
Henning Westerholt – https://skalatan.de/blog/
Kamailio services – https://gilawa.com<https://gilawa.com/>
From: sr-users <sr-users-bounces(a)lists.kamailio.org> On Behalf Of sthustfo
Sent: Tuesday, October 11, 2022 4:50 AM
To: sr-users(a)lists.kamailio.org
Subject: Re: [SR-Users] detect tcp connection close using tcpops module
Any pointers on what I am missing would be highly appreciated. The event routes are being
called but the $conid does not contain the proper value.
------- Original Message -------
On Sunday, October 9th, 2022 at 20:55, sthustfo
<sthustfo@proton.me<mailto:sthustfo@proton.me>> wrote:
Looking at the source code, it seems the extra_data is not set. But that does not explain
why $conid is <null> when tcp:closed event route is triggered.
------- Original Message -------
On Sunday, October 9th, 2022 at 19:55, sthustfo
<sthustfo@proton.me<mailto:sthustfo@proton.me>> wrote:
I am running latest kamailio 5.6.2 and attempting to detect tcp/tls connection being
disconnected or closed using tcpops module. As suggested in tcpops documentation at
https://www.kamailio.org/docs/modules/devel/modules/tcpops.html, registered event routes
as below.
event_route[tcp:closed] {
xlog("L_INFO", "$proto connection closed ($conid)\n");
}
event_route[tcp:timeout] {
xlog("L_INFO", "$proto connection timed out ($conid)\n");
}
event_route[tcp:reset] {
xlog("L_INFO", "$proto connection reset by peer ($conid)\n");
}
Now it is observed that the event route is being called but the $conid is not set. The
logs show the below log statements and extra data is (nil).
24(4263) DEBUG: <core> [core/tcp_read.c:284]: tcp_read_data(): EOF on connection
0x7ffff2ff8b90 (state: 0, flags: 4018) - FD 7, bytes 0, rd-flags 10000
([10.8.137.33]:51069 -> [10.8.137.33]:5060)24(4263) DEBUG: <core>
[core/tcp_read.c:1500]: tcp_read_req(): EOF
24(4263) DEBUG: <core> [core/io_wait.h:600]: io_watch_del(): DBG: io_watch_del
(0x555555ab6960, 7, -1, 0x10) fd_no=2 called
24(4263) DEBUG: <core> [core/tcp_read.c:1870]: handle_io(): removing from list
0x7ffff2ff8b90 id 1 fd 7, state 2, flags 4018, main fd 51, refcnt 2 ([10.8.137.33]:51069
-> [10.8.137.33]:5060)
24(4263) DEBUG: <core> [core/tcp_read.c:1653]: release_tcpconn(): releasing con
0x7ffff2ff8b90, state -1, fd=7, id=1 ([10.8.137.33]:51069 -> [10.8.137.33]:5060)
24(4263) DEBUG: <core> [core/tcp_read.c:1657]: release_tcpconn(): extra_data (nil)
32(4271) DEBUG: <core> [core/tcp_main.c:3651]: handle_tcp_child(): reader response=
7ffff2ff8b90, -1 from 0
32(4271) DEBUG: <core> [core/tcp_main.c:3576]: tcp_emit_closed_event(): TCP closed
event creation triggered (reason: 0)
32(4271) DEBUG: tcpops [tcpops.c:295]: tcpops_handle_tcp_closed(): received TCP closed
event
32(4271) DEBUG: tcpops [tcpops.c:249]: tcpops_tcp_closed_run_route(): event reason id: 0
rt: 1
32(4271) DEBUG: <core> [core/parser/parse_fline.c:249]: parse_first_line(): first
line type 1 (request) flags 1
32(4271) DEBUG: <core> [core/parser/msg_parser.c:679]: parse_msg(): SIP Request:
32(4271) DEBUG: <core> [core/parser/msg_parser.c:681]: parse_msg(): method:
<OPTIONS>
32(4271) DEBUG: <core> [core/parser/msg_parser.c:683]: parse_msg(): uri:
<sip:you@kamailio.org<mailto:sip:you@kamailio.org>>
32(4271) DEBUG: <core> [core/parser/msg_parser.c:685]: parse_msg(): version:
<SIP/2.0>
32(4271) DEBUG: <core> [core/parser/parse_hname2.c:301]: parse_sip_header_name():
parsed header name [Via] type 1
32(4271) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header
reached, state=2
32(4271) DEBUG: <core> [core/parser/msg_parser.c:555]: parse_headers(): Via found,
flags=2
32(4271) DEBUG: <core> [core/parser/msg_parser.c:557]: parse_headers(): this is the
first via
32(4271) exec: *** cfgtrace:dbg_cfg_trace(): unknown_route=[tcp:closed]
c=[/usr/local/etc/kamailio/kamailio.cfg] l=976 a=26 n=xlog
32(4271) INFO: <script> tcp connection closed (<null>)
Can anyone provide any pointers on what I am missing?
Thanks in advance.
773
days inactive
775
days old
3 comments
2 participants
participants (2)
-
Henning Westerholt -
sthustfo