[sheepdog] [PATCH RFC 1/3] logger: format in logger process

[Hitoshi Mitake]

Current sheep formats log lines in sheep process, before sending them
to logger process. This patch moves the formatting from sheep to
logger because it will make a noise for workload of sheep (of course
they are sublte but it is better to do this).

Signed-off-by: Hitoshi Mitake <mitake.hitoshi at lab.ntt.co.jp>
---
 lib/logger.c |   53 +++++++++++++++++++++++++++++++++--------------------
 1 files changed, 33 insertions(+), 20 deletions(-)

diff --git a/lib/logger.c b/lib/logger.c
index 779f7fa..2dc7ce1 100644
--- a/lib/logger.c
+++ b/lib/logger.c
@@ -35,9 +35,6 @@
 #include "logger.h"
 #include "util.h"
 
-static int log_vsnprintf(char *buff, size_t size, int prio,
-			 const char *func, int line, const char *fmt,
-			 va_list ap) __attribute__ ((format (printf, 6, 0)));
 static void dolog(int prio, const char *func, int line, const char *fmt,
 		  va_list ap) __attribute__ ((format (printf, 4, 0)));
 
@@ -58,8 +55,15 @@ struct logarea {
 	int fd;
 };
 
+#define FUNC_NAME_SIZE 32 /* according to C89, including '\0' */
 struct logmsg {
+	time_t t;
 	int prio;
+	char func[FUNC_NAME_SIZE];
+	int line;
+	char worker_name[MAX_THREAD_NAME_LEN];
+	int worker_idx;
+
 	char str[0];
 };
 
@@ -149,33 +153,31 @@ static void notrace free_logarea(void)
 	shmdt(la);
 }
 
-static notrace int log_vsnprintf(char *buff, size_t size, int prio,
-				 const char *func, int line, const char *fmt,
-				 va_list ap)
+static notrace int default_log_format(char *buff, size_t size,
+				const struct logmsg *msg)
 {
 	char *p = buff;
-	time_t t = time(NULL);
 	struct tm tm;
+	int worker_name_len = strlen(msg->worker_name);
 
-	localtime_r(&t, &tm);
-
-	strftime(p, size, "%b %2d %H:%M:%S ", &tm);
+	localtime_r(&msg->t, &tm);
+	strftime(p, size, "%b %2d %H:%M:%S ", (const struct tm *)&tm);
 	p += strlen(p);
 
-	if (worker_name && worker_idx)
-		snprintf(p, size, "[%s %d] ", worker_name, worker_idx);
-	else if (worker_name)
-		snprintf(p, size, "[%s] ", worker_name);
+	if (worker_name_len && msg->worker_idx)
+		snprintf(p, size, "[%s %d] ", msg->worker_name,
+			msg->worker_idx);
+	else if (worker_name_len)
+		snprintf(p, size, "[%s] ", msg->worker_name);
 	else
 		pstrcpy(p, size, "[main] ");
 
 	p += strlen(p);
-	snprintf(p, size - strlen(buff), "%s(%d) ", func, line);
 
+	snprintf(p, size - strlen(buff), "%s(%d) ", msg->func, msg->line);
 	p += strlen(p);
 
-	vsnprintf(p, size - strlen(buff), fmt, ap);
-
+	snprintf(p, size - strlen(buff), "%s", (char *)msg->str);
 	p += strlen(p);
 
 	return p - buff;
@@ -186,8 +188,10 @@ static notrace int log_vsnprintf(char *buff, size_t size, int prio,
  */
 static notrace void log_syslog(const struct logmsg *msg)
 {
-	char *str = (char *)msg->str;
+	char str[MAX_MSG_SIZE];
 
+	memset(str, 0, MAX_MSG_SIZE);
+	default_log_format(str, MAX_MSG_SIZE, msg);
 	if (log_fd >= 0)
 		xwrite(log_fd, str, strlen(str));
 	else
@@ -198,9 +202,10 @@ static notrace void dolog(int prio, const char *func, int line,
 		const char *fmt, va_list ap)
 {
 	char str[MAX_MSG_SIZE];
-	int len;
+	int len = 0;
+	time_t t = time(NULL);
 
-	len = log_vsnprintf(str, sizeof(str), prio, func, line, fmt, ap);
+	len = vsnprintf(str, MAX_MSG_SIZE, fmt, ap);
 
 	if (la) {
 		struct sembuf ops;
@@ -221,7 +226,15 @@ static notrace void dolog(int prio, const char *func, int line,
 		else {
 			/* ok, we can stage the msg in the area */
 			msg = (struct logmsg *)la->tail;
+
+			msg->t = t;
 			msg->prio = prio;
+			pstrcpy(msg->func, FUNC_NAME_SIZE, func);
+			msg->line = line;
+			if (worker_name)
+				pstrcpy(msg->worker_name, MAX_THREAD_NAME_LEN,
+					worker_name);
+			msg->worker_idx = worker_idx;
 			memcpy(msg->str, str, len + 1);
 			la->tail += sizeof(struct logmsg) + len + 1;
 		}
-- 
1.7.2.5