[sr-dev] [kamailio/kamailio] tcp_send_timeout not used on reused socket (Issue #3443)

9 May 2023

### Description

Having clients connected via TCP doing only passive connections in the kamailio server it
seems the tcp_send_timeout is not used on messages going out to the clients. While
tcp_keepalive is doing well as long as there was not sent any packet to the client
tcp_send_timout does nothing. The underlying Linux tries to send the SIP message for ages
(15 minutes in my case).

Do I have a wrong understanding of tcp_send_timeout?

I tried with tcp_async yes and no with same results.

### Troubleshooting

These are my tcp settings:

```
# def = 10 Time in seconds after a TCP connection will be closed if it is not available
for writing in this interval (and Kamailio wants to send something on it).
# Lower this value for faster detection of broken TCP connections.
tcp_send_timeout=3

tcp_connect_timeout=10  # def = 10
tcp_connection_lifetime=3605
tcp_rd_buf_size=32768
tcp_max_connections=2048
tcp_connection_match=1  # match also local port

tcp_keepalive=yes       # Enables keepalive for tcp (sets SO_KEEPALIVE socket option)
tcp_keepcnt=3           # Number of keepalives sent before dropping the connection
(TCP_KEEPCNT socket option). Linux only.
tcp_keepidle=30         # Time before starting to send keepalives, if the connection is
idle (TCP_KEEPIDLE socket option). Linux only.
tcp_keepintvl=10        # Time interval between keepalive probes, when the previous probe
failed (TCP_KEEPINTVL socket option). Linux only.

tcp_async=yes           # alias tcp_buf_write, default=yes
tcp_crlf_ping=no
```

I also tried to set the tcp_send_timeout to much too high value 333666 to trigger this
line of code in tcp_options.c:

```
WARN("%s: timeout too big (%u), the maximum value is %u\n",
                                name, *to, max_val);
```

But even in -d -d -d debugging that line never hits.

I do **not** make any connections outbound (senseless on NAT). Instead I'd like to
reject this:

```
                if ($dP =~ "tcp") {
                        set_forward_no_connect();
                        xlog("L_INFO", ">> checking tcp connection to
$dd:$dp");
                        if(tcp_get_conid("$dd:$dp", "$var(conid)")) {
                                xlog("L_INFO", ">> connection id to
$dd:$dp is: $var(conid)");
                        } else {
                                xlog("L_ERR", ">> connection to
$dd:$dp is no longer connected. Client must reregister!");
                                sl_send_reply("480", "TCP not
connected");
                                exit;
                        }
                }
```

But the connection ID is still there for a long time. And there are no keepalives done
since the outgoing packets are in the queue.

#### Reproduction

1. Register a client with TCP.
2. Pull the plug.
3. Make a call to it.
4. Run a `'watch 'netstat -tapen | grep <client_ip>'`: The connected
client never vanishes.
5. Run a `tcpdump -i ethX tcp port <kamailio_server_port>`: the system tries to send
the packet for a long time

#### Log Messages

There is not much to see in the log, even in debug level.

`/usr/sbin/kamailio -P /var/run/kamailio/kamailio.sbc.pid -f
/etc/kamailio.sbc/kamailio.cfg -m 48 -M 24 -u kamailio -g kamailio -d -d -d`

At that moment the switchport was already shutdown:

```
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: INFO: sbc:<script>: Network sending:
...

>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
INVITE sip:22@ws2.domain.tld;user=phone SIP/2.0
Record-Route: <sip:192.168.48.131:5065;r2=on;lr;ftag=97p54nlxgb;x-rtpp=1>
Record-Route: <sip:10.101.65.131:5082;r2=on;lr;ftag=97p54nlxgb;x-rtpp=1>
Via: SIP/2.0/UDP
192.168.48.131:5065;branch=z9hG4bKe01f.07e0d03fb0af18dcdb76154be67bea1d.0
Via: SIP/2.0/UDP
192.168.41.57:48310;received=10.101.65.130;branch=z9hG4bK-nzdt1be9c4xn;rport=48310
From: "01/301102-21" <sip:15553010221@ws2.domain.tld>;tag=97p54nlxgb
To: <sip:22@ws2.domain.tld;user=phone>
Call-ID: 3136383336323230393839333336-jg7spjsktbm2
CSeq: 2 INVITE
Max-Forwards: 69
User-Agent: snomD765/10.1.49.11
Contact:
<sip:15553010221@192.168.48.131:5065;ntv3=2;alias=10.101.65.130~48310~1;fs=udp:10.101.65.131:5082;uri=sip:15553010221%40192.168.41.57:48310%3bline%3dbq029ivo;line=bq029ivo>;reg-id=1
Accept: application/sdp
Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO,
UPDATE
Allow-Events: talk, hold, refer, call-info
Supported: timer, 100rel, replaces, from-change
Session-Expires: 3600
Min-SE: 90
Proxy-Authorization: Digest
username="45487cfdffef4777",realm="ws2.domain.tld",nonce="d84c8d657ba6e3081547bbb6e0c1817c",uri="sip:22@ws2.domain.tld;user=phone",qop=auth,nc=00000001,cnonce="6be15ae9",response="9455eafa4f6b2b78e971a87cb2716132",opaque="485307819b9fa9a1f7e2ca58ae77f795",algorithm=MD5
Content-Type: application/sdp
Content-Length: 258
P-Charging-Vector: icid-value=31363833363232;icid-generated-at=c5sbcp01t
X-User: <sip:45487cfdffef4777@ws2.domain.tld>
X-Location: dev.DefaultGroup;reg=192.168.48.68:5060;sig=192.168.48.74:5060;bt=0
X-Realm: p01t

v=0
o=root 711904586 711904586 IN IP4 10.101.65.133
s=call
c=IN IP4 10.101.65.133
t=0 0
m=audio 10490 RTP/AVP 9 8 101
a=rtpmap:9 G722/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=rtcp:10491
a=ptime:20

...

>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:tm [t_funcs.c:373]:
t_relay_to(): new transaction forwarded
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core> [core/receive.c:528]:
receive_msg(): request-route executed in: 45584 usec
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core> [core/usr_avp.c:637]:
destroy_avp_list(): destroying list (nil)
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core> [core/usr_avp.c:637]:
destroy_avp_list(): destroying list (nil)
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core> [core/usr_avp.c:637]:
destroy_avp_list(): destroying list (nil)
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core> [core/usr_avp.c:637]:
destroy_avp_list(): destroying list (nil)
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core> [core/usr_avp.c:637]:
destroy_avp_list(): destroying list (nil)
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core> [core/usr_avp.c:637]:
destroy_avp_list(): destroying list (nil)
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core> [core/xavp.c:541]:
xavp_destroy_list(): destroying xavp list (nil)
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core> [core/xavp.c:541]:
xavp_destroy_list(): destroying xavp list (nil)
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core> [core/xavp.c:541]:
xavp_destroy_list(): destroying xavp list (nil)
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core> [core/receive.c:628]:
receive_msg(): cleaning up
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core>
[core/parser/sdp/sdp.c:863]: free_sdp(): _sdp = 0x7fa8d478c728
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core>
[core/parser/sdp/sdp.c:865]: free_sdp(): sdp = 0x7fa8d44ef100
May  9 10:48:19 p01t-1 kamailio.sbc[150273]: DEBUG: sbc:<core>
[core/parser/sdp/sdp.c:867]: free_sdp(): session = 0x7fa8d44ee018

... 

May  9 10:48:19 p01t-1 kamailio.sbc[150271]: DEBUG: sbc:<core>
[core/tcp_main.c:1664]: _tcpconn_find(): found connection by peer address (id: 1)
May  9 10:48:19 p01t-1 kamailio.sbc[150271]: DEBUG: sbc:<core>
[core/tcp_main.c:2541]: tcpconn_send_put(): found fd in cache (11, 0x7fa8d0965140, 1)
May  9 10:48:19 p01t-1 kamailio.sbc[150271]: DEBUG: sbc:<core>
[core/tcp_main.c:2763]: tcpconn_do_send(): sending...
May  9 10:48:19 p01t-1 kamailio.sbc[150271]: DEBUG: sbc:<core>
[core/tcp_main.c:2796]: tcpconn_do_send(): after real write: c= 0x7fa8d0965140 n=1261
fd=11
May  9 10:48:19 p01t-1 kamailio.sbc[150271]: DEBUG: sbc:<core>
[core/tcp_main.c:2797]: tcpconn_do_send(): buf=
INVITE sip:22@192.168.41.157:39342;line=5z2d2k8i;ob SIP/2.0

...

```

Finally the Application Server in front cancels the call.

But look at this:

```
root@p01t-1:~# tcpdump -nn -i eth1 tcp port 5082
tcpdump: verbose output suppressed, use -v[v]... for full protocol decode
listening on eth1, link-type EN10MB (Ethernet), snapshot length 262144 bytes
10:47:31.915062 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [.], ack 3024626659,
win 501, options [nop,nop,TS val 924881395 ecr 4525523], length 0
10:47:31.916129 IP 10.101.65.130.39342 > 10.101.65.131.5082: Flags [.], ack 1, win
4836, options [nop,nop,TS val 4528662 ecr 924819977], length 0

10:48:02.635024 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [.], ack 1, win 501,
options [nop,nop,TS val 924912115 ecr 4528662], length 0
10:48:02.636100 IP 10.101.65.130.39342 > 10.101.65.131.5082: Flags [.], ack 1, win
4836, options [nop,nop,TS val 4531734 ecr 924819977], length 0

----- switch port port shutdown ------

----- make the call:

10:48:19.690401 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924929170 ecr 4531734], length 1261
10:48:19.899036 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924929379 ecr 4531734], length 1261
10:48:20.331011 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924929811 ecr 4531734], length 1261
10:48:21.194994 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924930675 ecr 4531734], length 1261
10:48:22.891001 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924932371 ecr 4531734], length 1261
10:48:26.446978 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924935927 ecr 4531734], length 1261
10:48:33.355070 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924942835 ecr 4531734], length 1261
10:48:40.011057 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924949491 ecr 4531734], length 1261
10:48:46.667041 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924956147 ecr 4531734], length 1261
10:48:53.323039 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924962803 ecr 4531734], length 1261
10:48:59.979042 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924969459 ecr 4531734], length 1261
10:49:06.635029 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924976115 ecr 4531734], length 1261
10:49:13.291079 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924982771 ecr 4531734], length 1261
10:49:19.947045 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924989427 ecr 4531734], length 1261
10:49:26.603048 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 924996083 ecr 4531734], length 1261
10:49:33.259016 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925002739 ecr 4531734], length 1261
10:49:39.915052 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925009395 ecr 4531734], length 1261
10:49:46.571046 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925016051 ecr 4531734], length 1261
10:49:53.227015 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925022707 ecr 4531734], length 1261
10:49:59.883017 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925029363 ecr 4531734], length 1261
10:50:06.539037 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925036019 ecr 4531734], length 1261
10:50:13.195051 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925042675 ecr 4531734], length 1261
10:50:19.850986 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925049331 ecr 4531734], length 1261
10:50:26.507018 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925055987 ecr 4531734], length 1261
10:50:33.163011 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925062643 ecr 4531734], length 1261
10:50:39.819015 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925069299 ecr 4531734], length 1261
10:50:46.475056 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925075955 ecr 4531734], length 1261
10:50:53.135023 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925082615 ecr 4531734], length 1261
10:51:00.043094 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925089523 ecr 4531734], length 1261
10:51:06.699024 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925096179 ecr 4531734], length 1261
10:51:13.355049 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925102835 ecr 4531734], length 1261
10:51:20.011080 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925109491 ecr 4531734], length 1261
10:51:26.667023 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925116147 ecr 4531734], length 1261
10:51:33.323042 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925122803 ecr 4531734], length 1261
10:51:39.979029 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925129459 ecr 4531734], length 1261
10:51:46.635040 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925136115 ecr 4531734], length 1261
10:51:53.291007 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925142771 ecr 4531734], length 1261
10:51:59.947009 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925149427 ecr 4531734], length 1261
10:52:06.603019 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925156083 ecr 4531734], length 1261
10:52:13.259033 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925162739 ecr 4531734], length 1261
10:52:19.915011 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925169395 ecr 4531734], length 1261
10:52:26.571014 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925176051 ecr 4531734], length 1261
10:52:33.227032 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925182707 ecr 4531734], length 1261
10:52:39.883041 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925189363 ecr 4531734], length 1261
10:52:46.539013 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925196019 ecr 4531734], length 1261
10:52:53.199018 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925202679 ecr 4531734], length 1261
10:53:00.107035 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925209587 ecr 4531734], length 1261
10:53:06.763039 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925216243 ecr 4531734], length 1261
10:53:13.419041 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925222899 ecr 4531734], length 1261
10:53:20.075014 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925229555 ecr 4531734], length 1261
10:53:26.731046 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925236211 ecr 4531734], length 1261
10:53:33.387027 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925242867 ecr 4531734], length 1261
10:53:40.043077 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925249523 ecr 4531734], length 1261
10:53:46.699076 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925256179 ecr 4531734], length 1261
10:53:53.355055 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925262835 ecr 4531734], length 1261
10:54:00.011019 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925269491 ecr 4531734], length 1261
10:54:06.667071 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925276147 ecr 4531734], length 1261
10:54:13.323026 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925282803 ecr 4531734], length 1261
10:54:19.979077 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925289459 ecr 4531734], length 1261
10:54:26.635284 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925296115 ecr 4531734], length 1261
10:54:33.291019 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925302771 ecr 4531734], length 1261
10:54:39.946998 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925309427 ecr 4531734], length 1261
10:54:46.603049 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925316083 ecr 4531734], length 1261
10:54:53.259008 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925322739 ecr 4531734], length 1261
10:54:59.915019 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925329395 ecr 4531734], length 1261
10:55:06.571100 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925336051 ecr 4531734], length 1261
10:55:13.227056 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925342707 ecr 4531734], length 1261
10:55:19.883016 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925349363 ecr 4531734], length 1261
10:55:26.539021 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925356019 ecr 4531734], length 1261
10:55:33.195043 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925362675 ecr 4531734], length 1261
10:55:39.850991 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925369331 ecr 4531734], length 1261
10:55:46.507013 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925375987 ecr 4531734], length 1261
10:55:53.163060 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925382643 ecr 4531734], length 1261
10:55:59.819014 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925389299 ecr 4531734], length 1261
10:56:06.475045 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925395955 ecr 4531734], length 1261
10:56:13.131065 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925402611 ecr 4531734], length 1261
10:56:19.787052 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925409267 ecr 4531734], length 1261
10:56:26.443048 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925415923 ecr 4531734], length 1261
10:56:33.099016 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925422579 ecr 4531734], length 1261
10:56:39.755032 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925429235 ecr 4531734], length 1261
10:56:46.411005 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925435891 ecr 4531734], length 1261
10:56:53.067116 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925442547 ecr 4531734], length 1261
10:56:59.723032 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925449203 ecr 4531734], length 1261
10:57:06.379062 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925455859 ecr 4531734], length 1261
10:57:13.035003 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925462515 ecr 4531734], length 1261
10:57:19.691077 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925469171 ecr 4531734], length 1261
10:57:26.347050 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925475827 ecr 4531734], length 1261
10:57:33.003004 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925482483 ecr 4531734], length 1261
10:57:39.659029 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925489139 ecr 4531734], length 1261
10:57:46.314989 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925495795 ecr 4531734], length 1261
10:57:52.971040 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925502451 ecr 4531734], length 1261
10:57:59.631026 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925509111 ecr 4531734], length 1261
10:58:06.539039 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925516019 ecr 4531734], length 1261
10:58:13.195056 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925522675 ecr 4531734], length 1261
10:58:19.851012 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925529331 ecr 4531734], length 1261
10:58:26.507049 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925535987 ecr 4531734], length 1261
10:58:33.163017 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925542643 ecr 4531734], length 1261
10:58:39.819091 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925549299 ecr 4531734], length 1261
10:58:46.475017 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925555955 ecr 4531734], length 1261
10:58:53.131046 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925562611 ecr 4531734], length 1261
10:58:59.786990 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925569267 ecr 4531734], length 1261
10:59:06.443029 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925575923 ecr 4531734], length 1261
10:59:13.099009 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925582579 ecr 4531734], length 1261
10:59:19.754984 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925589235 ecr 4531734], length 1261
10:59:26.411053 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925595891 ecr 4531734], length 1261
10:59:33.067041 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925602547 ecr 4531734], length 1261
10:59:39.723053 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925609203 ecr 4531734], length 1261
10:59:46.379016 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925615859 ecr 4531734], length 1261
10:59:53.035054 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925622515 ecr 4531734], length 1261
10:59:59.691058 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925629171 ecr 4531734], length 1261
11:00:06.347021 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925635827 ecr 4531734], length 1261
11:00:13.003052 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925642483 ecr 4531734], length 1261
11:00:19.659043 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925649139 ecr 4531734], length 1261
11:00:26.315011 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925655795 ecr 4531734], length 1261
11:00:32.971015 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925662451 ecr 4531734], length 1261
11:00:39.627039 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925669107 ecr 4531734], length 1261
11:00:46.283052 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925675763 ecr 4531734], length 1261
11:00:52.939024 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925682419 ecr 4531734], length 1261
11:00:59.595048 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925689075 ecr 4531734], length 1261
11:01:06.251017 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925695731 ecr 4531734], length 1261
11:01:12.907013 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925702387 ecr 4531734], length 1261
11:01:19.563042 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925709043 ecr 4531734], length 1261
11:01:26.219027 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925715699 ecr 4531734], length 1261
11:01:32.875010 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925722355 ecr 4531734], length 1261
11:01:39.531004 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925729011 ecr 4531734], length 1261
11:01:46.187040 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925735667 ecr 4531734], length 1261
11:01:52.843002 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925742323 ecr 4531734], length 1261
11:01:59.499048 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925748979 ecr 4531734], length 1261
11:02:06.155027 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925755635 ecr 4531734], length 1261
11:02:12.811044 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925762291 ecr 4531734], length 1261
11:02:19.467018 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925768947 ecr 4531734], length 1261
11:02:26.123041 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925775603 ecr 4531734], length 1261
11:02:32.779046 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925782259 ecr 4531734], length 1261
11:02:39.435015 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925788915 ecr 4531734], length 1261
11:02:46.091034 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925795571 ecr 4531734], length 1261
11:02:52.747128 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925802227 ecr 4531734], length 1261
11:02:59.403096 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925808883 ecr 4531734], length 1261
11:03:06.059012 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925815539 ecr 4531734], length 1261
11:03:12.715029 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925822195 ecr 4531734], length 1261
11:03:19.370993 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925828851 ecr 4531734], length 1261
11:03:26.027010 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925835507 ecr 4531734], length 1261
11:03:32.683029 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925842163 ecr 4531734], length 1261
11:03:39.339046 IP 10.101.65.131.5082 > 10.101.65.130.39342: Flags [P.], seq 1:1262,
ack 1, win 501, options [nop,nop,TS val 925848819 ecr 4531734], length 1261

```

### Possible Solutions

I have no idea why tcp_send_timeout is not set on the connected socket during spawning the
listener for this client.

### Additional Information

```
root@p01t-1:~# kamailio -V
version: kamailio 5.6.4 (x86_64/linux)
flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST,
DNS_IP_HACK, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY,
USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR,
USE_DST_BLOCKLIST, HAVE_RESOLV_RES, TLS_PTHREAD_MUTEX_SHARED
ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535,
DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown
compiled with gcc 10.2.1
```

* **Operating System**:

```
root@p01t-1:~# cat /etc/debian_version
11.7

Linux p01t-1.neotel.at 5.10.0-22-amd64 #1 SMP Debian 5.10.178-3 (2023-04-22) x86_64
GNU/Linux
```
[debug.log](https://github.com/kamailio/kamailio/files/11429302/debug.log)

-- 
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/3443
You are receiving this because you are subscribed to this thread.

Message ID: &lt;kamailio/kamailio/issues/3443(a)github.com&gt;

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

[sr-dev] [kamailio/kamailio] tcp_send_timeout not used on reused socket (Issue #3443)