Just had a look on this. Running rsyslog 8.1901 version we do see this behavior. Rsyslog receiver restarts, sends the FIN packet, client responds with ACK, but after a while it sends another message to the already closed socket. Not sure whether the behavior is correct or not. There is FIN ACK at 09:44:36.597404 and another message sent at 09:44:37.899188.
(tcpdump from client/relay 10.0.0.130, 10.0.0.138 is the receiver) 09:44:19.614994 IP 10.0.0.130.41498 > 10.0.0.138.2514: Flags [P.], seq 7629:7822, ack 1, win 502, options [nop,nop,TS val 2488259817 ecr 1259647639], length 193 .O..K...<30>1 2020-07-20T09:44:19+00:00 loco01-10.0.0.130 snmpd 629 - [syslogTimes@29171 10.0.0.130="2020-07-20T09:44:19.610564+00:00"] Connection from UDP: [10.0.0.20]:42624->[10.0.0.130]:161 09:44:19.615009 IP 10.0.0.138.2514 > 10.0.0.130.41498: Flags [.], ack 7822, win 8190, options [nop,nop,TS val 1259654040 ecr 2488259817], length 0 09:44:36.588199 IP 10.0.0.138.2514 > 10.0.0.130.41498: Flags [F.], seq 1, ack 7822, win 8190, options [nop,nop,TS val 1259671013 ecr 2488259817], length 0 09:44:36.597404 IP 10.0.0.130.41498 > 10.0.0.138.2514: Flags [.], ack 2, win 502, options [nop,nop,TS val 2488276799 ecr 1259671013], length 0 09:44:37.899188 IP 10.0.0.130.41498 > 10.0.0.138.2514: Flags [P.], seq 7822:8024, ack 2, win 502, options [nop,nop,TS val 2488278101 ecr 1259671013], length 202 .P.UK...<30>1 2020-07-20T11:44:37.894029+02:00 services-10.0.0.34 snmpd 1714 - [syslogTimes@29171 10.0.0.130="2020-07-20T09:44:37.894927+00:00"] Connection from UDP: [10.0.0.20]:47156->[10.0.0.34]:161 09:44:37.899213 IP 10.0.0.138.2514 > 10.0.0.130.41498: Flags [R], seq 3960804835, win 0, length 0 Peter On Wed, Apr 29, 2020 at 2:30 PM Rainer Gerhards <[email protected]> wrote: > oh, that's a good question - maybe I was on the wrong path. I need to > investigate. > > Rainer > > El mié., 29 abr. 2020 a las 13:45, Peter Viskup > (<[email protected]>) escribió: > > > > What's the purpose of inputs.timeout.shutdown then. > > Thought it should cover this scenario in a way that the clients will > have enough time to send the data from buffers before closing the socket. > > Shouldn't the listener wait the time defined in inputs.timeout.shutdown > for client's response with FIN,ACK? Would expect that. > > > > Peter > > > > On Wed, Apr 29, 2020 at 1:03 PM Rainer Gerhards < > [email protected]> wrote: > >> > >> no, the receiver shuts down as soon as possible. This is intended. > >> Otherwise you get even longer shutdown times. > >> > >> Rainer > >> > >> El mié., 29 abr. 2020 a las 13:00, Peter Viskup via rsyslog > >> (<[email protected]>) escribió: > >> > > >> > Just testing the message forwarding and reliability of plain TCP. Am > aware > >> > of the un-reliability of that forwarding. > >> > See some missing messages after the rsyslog proper process restart on > >> > destination side. > >> > Configured simple TCP omfwd action with keepalive enabled. > >> > On receiving side imptcp input with keepalive enabled and > >> > global(inputs.timeout.shutdown="10000"). > >> > Unfortunately see rsyslog going down and closing listeners too fast - > not > >> > accepting the timeout.shutdown value. After that the receiver does > not wait > >> > for FIN,ACK from client side and just close the socket. The data being > >> > flushed from buffer on client side are responded with RST packet. > Would > >> > expect the receiver to wait up to 10 seconds to let the clients flush > the > >> > data. Have some remote sites with slow link - due to long distance - > >> > causing the socket sending queue being occupied most of the time. > >> > > >> > Do not see this behavior as appropriate. Could anybody review the > code? Is > >> > it bug or configuration issue? > >> > > >> > Found this code: > >> > > https://github.com/rsyslog/rsyslog/blob/69f8e1d1f7fe62fd2c5f38a81d4102a9a62d1722/plugins/imptcp/imptcp.c#L2381 > >> > > >> > According to the documentation the two shutdown()s can be called > before > >> > close(), but are not strictly required. > >> > Digging a little deeper discovered SO_LINGER is referenced, but with > value > >> > of 0 > >> > > https://github.com/rsyslog/rsyslog/blob/6f74f7e7b43eb32ab165c5975a0f7777cbbf0f21/runtime/nsd_ptcp.c#L359 > >> > which might be ok as with plain TCP there is no data transferred to > >> > client from the listener. And the SO_LINGER covers only flush buffered > >> > output (does not wait for incoming data) > >> > > https://www.gnu.org/software/libc/manual/html_node/Opening-and-Closing-Files.html#Opening-and-Closing-Files > >> > > >> > Was not able to find the LINGERing on client side code. Traced socket > >> > handling in omfwd > >> > > https://github.com/rsyslog/rsyslog/blob/1f8f621a97df6b1989e1aebd8cb15cd6a552fa9c/tools/omfwd.c > >> > was able to find the abort data in netstrm driver > >> > > https://github.com/rsyslog/rsyslog/blob/6f74f7e7b43eb32ab165c5975a0f7777cbbf0f21/runtime/netstrm.c#L83 > >> > which seems related. > >> > Hopefully from the tcpdump that part of the code seems to be working > as it > >> > is seen the client is trying to flush the data, all of which are > responded > >> > with RST packet. > >> > Both sides are running Debian10 with Debian's rsyslog 8.1901.0-1. > >> > > >> > Any help to sort this out is appreciated. > >> > > >> > Peter > >> > _______________________________________________ > >> > rsyslog mailing list > >> > https://lists.adiscon.net/mailman/listinfo/rsyslog > >> > http://www.rsyslog.com/professional-services/ > >> > What's up with rsyslog? Follow https://twitter.com/rgerhards > >> > NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a > myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if > you DON'T LIKE THAT. > _______________________________________________ rsyslog mailing list https://lists.adiscon.net/mailman/listinfo/rsyslog http://www.rsyslog.com/professional-services/ What's up with rsyslog? Follow https://twitter.com/rgerhards NOTE WELL: This is a PUBLIC mailing list, posts are ARCHIVED by a myriad of sites beyond our control. PLEASE UNSUBSCRIBE and DO NOT POST if you DON'T LIKE THAT.
