[tarantool-patches] [log 1/1] log: Fix logging large objects

[Ilya Markov]

The bug was that logging we passed to function write
number of bytes which may be more than size of buffer.
This may happen because formatting log string we use vsnprintf which
returns number of bytes would be written to buffer, not the actual
number.

Fix this with limiting number of bytes passing to write function.

Close #3248
---
 src/say.c                    | 24 ++++++++++++++++++------
 test/app-tap/logger.test.lua |  9 +++++++--
 2 files changed, 25 insertions(+), 8 deletions(-)

diff --git a/src/say.c b/src/say.c
index b92514d..8a8d46a 100644
--- a/src/say.c
+++ b/src/say.c
@@ -842,6 +842,18 @@ say_format_syslog(struct log *log, char *buf, int len, int level, const char *fi
 enum { SAY_BUF_LEN_MAX = 16 * 1024 };
 static __thread char buf[SAY_BUF_LEN_MAX];
 
+/**
+ * Wrapper over write which ensures, that writes not more than buffer size.
+ */
+static ssize_t
+safe_write(int fd, const char *buf, int size)
+{
+	/* Writes at most SAY_BUF_LEN_MAX - 1
+	 * (1 byte was taken for 0 byte in vsnprintf).
+	 */
+	return write(fd, buf, MIN(size, SAY_BUF_LEN_MAX - 1));
+}
+
 static void
 say_default(int level, const char *filename, int line, const char *error,
 	    const char *format, ...)
@@ -852,7 +864,7 @@ say_default(int level, const char *filename, int line, const char *error,
 	int total = log_vsay(log_default, level, filename,
 			     line, error, format, ap);
 	if (level == S_FATAL && log_default->fd != STDERR_FILENO) {
-		ssize_t r = write(STDERR_FILENO, buf, total);
+		ssize_t r = safe_write(STDERR_FILENO, buf, total);
 		(void) r;                       /* silence gcc warning */
 	}
 
@@ -870,7 +882,7 @@ write_to_file(struct log *log, int total)
 	       log->type == SAY_LOGGER_PIPE ||
 	       log->type == SAY_LOGGER_STDERR);
 	assert(total >= 0);
-	ssize_t r = write(log->fd, buf, total);
+	ssize_t r = safe_write(log->fd, buf, total);
 	(void) r;                               /* silence gcc warning */
 }
 
@@ -882,7 +894,7 @@ write_to_syslog(struct log *log, int total)
 {
 	assert(log->type == SAY_LOGGER_SYSLOG);
 	assert(total >= 0);
-	if (log->fd < 0 || write(log->fd, buf, total) <= 0) {
+	if (log->fd < 0 || safe_write(log->fd, buf, total) <= 0) {
 		/*
 		 * Try to reconnect, if write to syslog has
 		 * failed. Syslog write can fail, if, for example,
@@ -899,7 +911,7 @@ write_to_syslog(struct log *log, int total)
 			 * it would block thread. Try to reconnect
 			 * on next vsay().
 			 */
-			ssize_t r = write(log->fd, buf, total);
+			ssize_t r = safe_write(log->fd, buf, total);
 			(void) r;               /* silence gcc warning */
 		}
 	}
@@ -1041,11 +1053,11 @@ log_vsay(struct log *log, int level, const char *filename, int line,
 	case SAY_LOGGER_SYSLOG:
 		write_to_syslog(log, total);
 		if (level == S_FATAL && log->fd != STDERR_FILENO)
-			(void) write(STDERR_FILENO, buf, total);
+			(void) safe_write(STDERR_FILENO, buf, total);
 		break;
 	case SAY_LOGGER_BOOT:
 	{
-		ssize_t r = write(STDERR_FILENO, buf, total);
+		ssize_t r = safe_write(STDERR_FILENO, buf, total);
 		(void) r;                       /* silence gcc warning */
 		break;
 	}
diff --git a/test/app-tap/logger.test.lua b/test/app-tap/logger.test.lua
index 72d13d3..85f6166 100755
--- a/test/app-tap/logger.test.lua
+++ b/test/app-tap/logger.test.lua
@@ -1,7 +1,7 @@
 #!/usr/bin/env tarantool
 
 local test = require('tap').test('log')
-test:plan(23)
+test:plan(24)
 
 --
 -- Check that Tarantool creates ADMIN session for #! script
@@ -91,6 +91,11 @@ local line = file:read()
 message = json.decode(line)
 test:is(message.message, "this is \"", "check message with escaped character")
 
+-- gh-3248 trash in log file with logging large objects
+log.info(string.rep('a', 32000))
+line = file:read()
+test:ok(line:len() < 20000, "big line truncated")
+
 log.info("json")
 local line = file:read()
 message = json.decode(line)
@@ -100,7 +105,7 @@ log.info("hello")
 line = file:read()
 test:ok(not line:match("{"), "log change format")
 s, e = pcall(log.log_format, "non_format")
-test:ok(not s)
+test:ok(not s, "bad format")
 file:close()
 
 log.log_format("json")
-- 
2.7.4