Openssl SSL3_WRITE_PENDING error correction
Hi All! We've found a bug in the log_proto_framed_client. The bug is the following: - using ssl communication between the server and client. - using syslog protocol - If client send messages faster than the server can process messages, then the client go into the SSL3_WRITE_PENDING openssl error and close the connection. partial message handling correction: the flush is called only if proto have partially sent message after flush is called log_proto_text_client_post have to return because the post send one message per call it is important in case of framed messages diff --git a/lib/logproto.c b/lib/logproto.c index d821275..7f2f897 100644 --- a/lib/logproto.c +++ b/lib/logproto.c @@ -145,9 +145,13 @@ log_proto_text_client_post(LogProto *s, guchar *msg, gsize msg_len, gboolean *co g_assert(self->super.convert == (GIConv) -1); *consumed = FALSE; - rc = log_proto_flush(s); - if (rc == LPS_ERROR) - goto write_error; + if(self->partial) + { + rc = log_proto_flush(s); + if (rc == LPS_ERROR) + goto write_error; + return rc; + } /* OK, partial buffer empty, now flush msg that we just got */ @@ -1774,6 +1778,7 @@ log_proto_framed_client_new(LogTransport *transport) self->super.super.prepare = log_proto_text_client_prepare; self->super.super.post = log_proto_framed_client_post; + self->super.super.flush = log_proto_text_client_flush; self->super.super.transport = transport; self->super.super.convert = (GIConv) -1; return &self->super.super; Best Regards, Viktor
Hi, Thanks for your contribution, very good catch. I've integrated it with slight changes, as your patch returned from the function even when it wouldn't need to. Also, I've added a detailed comment on the problem to the source code, so that we'll remember why it is implemented that way. :) PS: your e-mail client clobbered the patch, please set it not to break lines, and keep tabs intact. Thanks. PS/2: please add proper "Signed-off-by" to your patches to give proper attribution and to track copyrights within the source code. Thanks. On Fri, 2011-04-01 at 14:28 +0200, Juhasz Viktor wrote:
Hi All!
We've found a bug in the log_proto_framed_client. The bug is the following: - using ssl communication between the server and client. - using syslog protocol - If client send messages faster than the server can process messages, then the client go into the SSL3_WRITE_PENDING openssl error and close the connection.
partial message handling correction:
the flush is called only if proto have partially sent message after flush is called log_proto_text_client_post have to return because the post send one message per call it is important in case of framed messages
diff --git a/lib/logproto.c b/lib/logproto.c index d821275..7f2f897 100644 --- a/lib/logproto.c +++ b/lib/logproto.c @@ -145,9 +145,13 @@ log_proto_text_client_post(LogProto *s, guchar *msg, gsize msg_len, gboolean *co g_assert(self->super.convert == (GIConv) -1);
*consumed = FALSE; - rc = log_proto_flush(s); - if (rc == LPS_ERROR) - goto write_error; + if(self->partial) + { + rc = log_proto_flush(s); + if (rc == LPS_ERROR) + goto write_error; + return rc; + }
if there's a partial packet, and log_proto_flush() successfully empties it, we don't need to return immediately from this function. Doing it this way adds another poll() iteration's latency to the processing. doing it this way achieves the same but without adding another iteration: rc = log_proto_flush(s); if (rc == LPS_ERROR) goto write_error; else if(self->partial) return rc; This patch does it: $ git show commit 3fa8e900453fb6af1767caf42e17ab6d8c42452b Author: Balazs Scheidler <bazsi@balabit.hu> Date: Sat Apr 2 09:59:33 2011 +0200 syslog() destination driver: fixed potential framing problem on contended connections In case the sender is too slow processing messages, the syslog() driver may get an SSL3_WRITE_PENDING error if TLS is enabled, or may generate an invalid framing if it is not. Both will cause the connection to be broken: in the SSL case by the client, in the non-SSL case by the server. The reason is, that in some cases LogProtoFramedClient could attempt 2 write operations in the same poll iteration, even if the first one already returned partial success. The 1st such operation is potentially a frame header, the 2nd is the message payload. The problem happens if we can't fully write the frame header. Signed-off-by: Viktor Juhasz <jviktor@balabit.hu> Signed-off-by: Balazs Scheidler <bazsi@balabit.hu>
/* OK, partial buffer empty, now flush msg that we just got */
@@ -1774,6 +1778,7 @@ log_proto_framed_client_new(LogTransport *transport)
self->super.super.prepare = log_proto_text_client_prepare; self->super.super.post = log_proto_framed_client_post; + self->super.super.flush = log_proto_text_client_flush; self->super.super.transport = transport; self->super.super.convert = (GIConv) -1; return &self->super.super;
Best Regards, Viktor
______________________________________________________________________________ Member info: https://lists.balabit.hu/mailman/listinfo/syslog-ng Documentation: http://www.balabit.com/support/documentation/?product=syslog-ng FAQ: http://www.campin.net/syslog-ng/faq.html
-- Bazsi
Saturday 02 of April 2011 10:07:51 Balazs Scheidler napisał(a):
I've integrated it with slight changes, as your patch returned from the function even when it wouldn't need to. Also, I've added a detailed comment on the problem to the source code, so that we'll remember why it is implemented that way. :)
[...]
$ git show commit 3fa8e900453fb6af1767caf42e17ab6d8c42452b Author: Balazs Scheidler <bazsi@balabit.hu> Date: Sat Apr 2 09:59:33 2011 +0200
syslog() destination driver: fixed potential framing problem on contended connections
Any chances to get that backported to 3.2 as well? I think I'm seeing this kind of behaviour (without SSL) here, I just can't nail it down. Regards, -- Jakub Jankowski|shasta@toxcorp.com|http://toxcorp.com/ GPG: FCBF F03D 9ADB B768 8B92 BB52 0341 9037 A875 942D
On Fri, 2011-04-08 at 12:51 +0200, Jakub Jankowski wrote:
Saturday 02 of April 2011 10:07:51 Balazs Scheidler napisał(a):
I've integrated it with slight changes, as your patch returned from the function even when it wouldn't need to. Also, I've added a detailed comment on the problem to the source code, so that we'll remember why it is implemented that way. :)
[...]
$ git show commit 3fa8e900453fb6af1767caf42e17ab6d8c42452b Author: Balazs Scheidler <bazsi@balabit.hu> Date: Sat Apr 2 09:59:33 2011 +0200
syslog() destination driver: fixed potential framing problem on contended connections
Any chances to get that backported to 3.2 as well? I think I'm seeing this kind of behaviour (without SSL) here, I just can't nail it down.
I _think_ it doesn't affect 3.2. Stared at the code for 5 minutes, but I can't see the state machine to have the same problem, since 3.3 added output buffering, which involves flushes, and the problem was there. However another problem was fixed just two weeks ago, with similar symptoms. Search for "Syslog-ng returning a TCP Reset" thread on this mailing list. -- Bazsi
Saturday 09 of April 2011 22:25:43 Balazs Scheidler napisał(a):
syslog() destination driver: fixed potential framing problem on contended connections
Any chances to get that backported to 3.2 as well? I think I'm seeing this kind of behaviour (without SSL) here, I just can't nail it down.
I _think_ it doesn't affect 3.2. Stared at the code for 5 minutes, but I can't see the state machine to have the same problem, since 3.3 added output buffering, which involves flushes, and the problem was there.
However another problem was fixed just two weeks ago, with similar symptoms.
Search for "Syslog-ng returning a TCP Reset" thread on this mailing list.
Thanks for the pointer. I applied dfc09fa50688600187f6c3e25f65a5c7877e924c to 3.2.2 and it fixed my issue. Regards, -- Jakub Jankowski|shasta@toxcorp.com|http://toxcorp.com/ GPG: FCBF F03D 9ADB B768 8B92 BB52 0341 9037 A875 942D
participants (3)
-
Balazs Scheidler
-
Jakub Jankowski
-
Juhasz Viktor