On Tue, 2008-11-04 at 11:47 -0800, Evan Rempel wrote:
First, were there any changes to the buffer/reopen code in 2.0.9 that may fix "lost" messages.
My host turtle lost connection to the syslog server, and upon regaining connection did not send all (any?) of the buffered messages.
This is only the syslog-ng stats messages, there were lots of other message that didn't "make it" to the server, but I wanted to show the problem with the smallest number, AND show that syslog-ng did NOT report that it dropped any messages.
------------------------------- Client (turtle)
2008-11-03T15:39:49-08:00 local@turtle.comp.uvic.ca syslog.info syslog-ng[3232]: Log statistics; dropped='tcp(AF_INET(142.104.5.206:514))=0', dropped='tcp(AF_INET(142.104.246.92:514))=0'
2008-11-03T15:49:49-08:00 local@turtle.comp.uvic.ca syslog.info syslog-ng[3232]: Log statistics; dropped='tcp(AF_INET(142.104.5.206:514))=0', dropped='tcp(AF_INET(142.104.246.92:514))=0'
2008-11-03T15:55:15-08:00 local@turtle.comp.uvic.ca syslog.err syslog-ng[3232]: EOF occurred while idle; fd='7'
2008-11-03T15:55:15-08:00 local@turtle.comp.uvic.ca syslog.err syslog-ng[3232]: Connection broken; time_reopen='5'
2008-11-03T15:59:49-08:00 local@turtle.comp.uvic.ca syslog.info syslog-ng[3232]: Log statistics; dropped='tcp(AF_INET(142.104.5.206:514))=0', dropped='tcp(AF_INET(142.104.246.92:514))=0'
2008-11-03T16:09:49-08:00 local@turtle.comp.uvic.ca syslog.info syslog-ng[3232]: Log statistics; dropped='tcp(AF_INET(142.104.5.206:514))=0', dropped='tcp(AF_INET(142.104.246.92:514))=0'
----------------- On the syslog server
2008-11-03T15:39:49-08:00 local@turtle.comp.uvic.ca/turtle.comp.uvic.ca syslog.info syslog-ng[3232]: Log statistics; dropped='tcp(AF_INET(142.104.5.206:514))=0', dropped='tcp(AF_INET(142.104.246.92:514))=0'
2008-11-03T15:55:15-08:00 local@turtle.comp.uvic.ca/turtle.comp.uvic.ca syslog.err syslog-ng[3232]: EOF occurred while idle; fd='7'
2008-11-03T15:55:15-08:00 local@turtle.comp.uvic.ca/turtle.comp.uvic.ca syslog.err syslog-ng[3232]: Connection broken; time_reopen='5'
2008-11-03T15:59:49-08:00 local@turtle.comp.uvic.ca/turtle.comp.uvic.ca syslog.info syslog-ng[3232]: Log statistics; dropped='tcp(AF_INET(142.104.5.206:514))=0', dropped='tcp(AF_INET(142.104.246.92:514))=0'
2008-11-03T16:09:49-08:00 local@turtle.comp.uvic.ca/turtle.comp.uvic.ca syslog.info syslog-ng[3232]: Log statistics; dropped='tcp(AF_INET(142.104.5.206:514))=0', dropped='tcp(AF_INET(142.104.246.92:514))=0'
------------------------------ The message with time stamp of 2008-11-03T15:49:49-08:00 did not get recorded at the server.
The EOF actually occurred due to a reload of the iptables, which then started blocking responses from the syslog server (142.104.246.92) until the connection was reopened by the client (142.104.5.223).
2008-11-03T15:31:17-08:00 local@turtle.comp.uvic.ca local7.notice iptables: succeeded
2008-11-03T15:39:50-08:00 local@turtle.comp.uvic.ca kern.warning kernel: iptables: IN=eth0 OUT= MAC=00:09:6b:89:ca:ec:00:0a:42:cb:84:00:08:00 SRC=142.104.246.92 DST=142.104.5.223 LEN=52 TOS=0x00 PREC=0x00 TTL=61 ID=23252 DF PROTO=TCP SPT=514 DPT=55411 WINDOW=350 RES=0x00 ACK URGP=0
... 14 other packets dropped
2008-11-03T15:53:15-08:00 local@turtle.comp.uvic.ca kern.warning kernel: iptables: IN=eth0 OUT= MAC=00:09:6b:89:ca:ec:00:0a:42:cb:84:00:08:00 SRC=142.104.246.92 DST=142.104.5.223 LEN=64 TOS=0x00 PREC=0x00 TTL=61 ID=23282 DF PROTO=TCP SPT=514 DPT=55411 WINDOW=350 RES=0x00 ACK URGP=0
This problem has been known for some time: the lack of application layer acknowledgements. The problem is that the only possible solution is to change the syslog protocol, and no, the latest IETF drafts don't solve this issue either. The problem is that syslog-ng assumes that a given chunk of data is sent, when it invokes the send() system call, but some cases the data sent might still be sitting in the socket output buffer. But syslog-ng did not get an error code to react on. As I said, if I invented some kind of app layer acknowledgement and the receiver would ACK back received data, it'd be possible to detect which messages made it to the server. The core infrastructure to support this is already implemented in the 3.0 branch, only the protocol part is missing. what this means, that with the current infrastructure, connection breaks will probably result in message loss. if the connection is broken actively (e.g. the receiver properly closes the channel), then syslog-ng will notice this, but this only means that the window of opportunity is smaller. -- Bazsi