From: Vladimír Čunát <vladimir.cunat@nic.cz>
Date: Tue, 5 Mar 2019 13:56:38 +0000 (+0100)
Subject: treewide: fix flushing of messages to logs in some cases
X-Git-Tag: v4.0.0~29^2
X-Git-Url: http://git.ipfire.org/gitweb/?a=commitdiff_plain;h=09fac26c9d18d4857001bfef098361ad4a9fd7af;p=thirdparty%2Fknot-resolver.git

treewide: fix flushing of messages to logs in some cases

... by setting FILE* properties and replace the explicit flushes.
Explicit flushing couldn't be well done e.g. for lua's error() function.
In particular, we had problems with journald not getting logs timely.
---

diff --git a/NEWS b/NEWS
index f8c216e43..3d6960229 100644
--- a/NEWS
+++ b/NEWS
@@ -14,6 +14,7 @@ Bugfixes
 - policy module: support '#' for separating port numbers, for consistency
 - fix startup on macOS+BSD when </dev/null and cqueues installed
 - policy.RPZ: log problems from zone-file level of parser as well (#453)
+- fix flushing of messages to logs in some cases (!781)
 
 Improvements
 ------------
diff --git a/daemon/main.c b/daemon/main.c
index 906b2f1ec..30abf8368 100644
--- a/daemon/main.c
+++ b/daemon/main.c
@@ -173,7 +173,6 @@ static void tty_process_input(uv_stream_t *stream, ssize_t nread, const uv_buf_t
 		lua_settop(L, 0);
 	}
 finish:
-	fflush(out);
 	free(cmd);
 	/* Close if redirected */
 	if (stream_fd != STDIN_FILENO) {
@@ -420,6 +419,12 @@ static int run_worker(uv_loop_t *loop, struct engine *engine, fd_array_t *ipc_se
 		return 1;
 	}
 
+	if (setvbuf(stdout, NULL, _IONBF, 0) || setvbuf(stderr, NULL, _IONBF, 0)) {
+		kr_log_error("[system] failed to to set output buffering (ignored): %s\n",
+				strerror(errno));
+		fflush(stderr);
+	}
+
 	/* Control sockets or TTY */
 	auto_free char *sock_file = NULL;
 	uv_pipe_t pipe;
@@ -428,7 +433,6 @@ static int run_worker(uv_loop_t *loop, struct engine *engine, fd_array_t *ipc_se
 	if (args->interactive) {
 		if (!args->quiet)
 			printf("[system] interactive mode\n> ");
-		fflush(stdout);
 		uv_pipe_open(&pipe, 0);
 		uv_read_start((uv_stream_t*) &pipe, tty_alloc, tty_process_input);
 	} else {
diff --git a/lib/utils.c b/lib/utils.c
index a3bf7ca96..6e63f9971 100644
--- a/lib/utils.c
+++ b/lib/utils.c
@@ -118,12 +118,11 @@ bool kr_verbose_set(bool status)
 
 void kr_log_verbose(const char *fmt, ...)
 {
-	if (kr_verbose_status) {
+	if (unlikely(kr_verbose_status)) {
 		va_list args;
 		va_start(args, fmt);
 		vprintf(fmt, args);
 		va_end(args);
-		fflush(stdout);
 	}
 }
 
@@ -141,7 +140,6 @@ void kr_log_qverbose_impl(const struct kr_query *qry, const char *cls, const cha
 	va_start(args, fmt);
 	vprintf(fmt, args);
 	va_end(args);
-	fflush(stdout);
 }
 
 bool kr_log_trace(const struct kr_query *query, const char *source, const char *fmt, ...)
diff --git a/lib/utils.h b/lib/utils.h
index a515a3880..8deef4efe 100644
--- a/lib/utils.h
+++ b/lib/utils.h
@@ -46,7 +46,7 @@ typedef void (*trace_callback_f)(struct kr_request *request);
 /** @brief Callback for request logging handler. */
 typedef void (*trace_log_f)(const struct kr_query *query, const char *source, const char *msg);
 
-#define kr_log_info(...) do { printf(__VA_ARGS__); fflush(stdout); } while(0)
+#define kr_log_info printf
 #define kr_log_error(...) fprintf(stderr, ## __VA_ARGS__)
 
 /* Always export these, but override direct calls by macros conditionally. */