diff mbox

[2/6] xenconsoled: switch hypervisor log to use logfile abstraction

Message ID 1465228781-22754-3-git-send-email-wei.liu2@citrix.com (mailing list archive)
State New, archived
Headers show

Commit Message

Wei Liu June 6, 2016, 3:59 p.m. UTC 
To minimise code churn, copy and paste a some existing functions and
adapt them to write to logfile. The functions to deal with fd directly
will go away eventually.

Signed-off-by: Wei Liu <wei.liu2@citrix.com>
---
 tools/console/daemon/io.c | 95 +++++++++++++++++++++++++++++++++++------------
 1 file changed, 71 insertions(+), 24 deletions(-)

Comments

Ian Jackson July 8, 2016, 4:58 p.m. UTC | #1 
Wei Liu writes ("[PATCH 2/6] xenconsoled: switch hypervisor log to use logfile abstraction"):
> To minimise code churn, copy and paste a some existing functions and
> adapt them to write to logfile. The functions to deal with fd directly
> will go away eventually.
...
> +static int write_logfile(struct logfile *logfile, const char *buf,
> +			 size_t len)
> +{
> +	ssize_t r = logfile_append(logfile, buf, len);
> +
> +	if (r < 0) return -1;
> +	return 0;
> +}

That this is necessary suggests that logfile_append has an
inconvenient calling convention.

> +static int write_logfile_with_timestamp(struct logfile *logfile,
> +					const char *data, size_t sz,
> +					int *needts)
> +{

This should be in logfile.c.  Furthermore, this is at the wrong level
with respect to log rotation:

> +		if ((*needts && logfile_append(logfile, ts, tslen))

This could result in a timestamp being split across two different
logfiles which is undesirable.  So I think this needs to be done at
the layer below.

> +		data = nl + 1;
> +		if (found_nl) {
> +			// If we printed a newline, strip all \r following it
> +			while (data <= last_byte && *data == '\r')
> +				data++;
> +		}

I would prefer that we only apply a lossless transformation to
logfiles, even if that means that our lotfiles contain CRs.  Also,
this is rather odd.  Surely it is more usual for the CR to precede the
LF.

I suggest the transformation `after every LF, preface the next byte
with the timestamp of that next byte'.

> -	if (fd != -1 && log_time_hv) {
> -		if (write_with_timestamp(fd, "Logfile Opened\n",
> -					 strlen("Logfile Opened\n"),
> -					 &log_time_hv_needts) < 0) {
> +
> +	if (tmp && log_time_hv) {
> +		if (write_logfile_with_timestamp(tmp, "Logfile Opened\n",
> +						 strlen("Logfile Opened\n"),
> +						 &log_time_hv_needts) < 0) {

I think that if timestamps are turned off, writing the "Logfile
Opened" (with no preceding timestamp) is probably a good idea.  So
this can be made simpler.

>  	if (log_hv) {
> -		if (log_hv_fd != -1)
> -			close(log_hv_fd);
> -		log_hv_fd = create_hv_log();
> +		if (log_hv_file)
> +			logfile_free(log_hv_file);
> +		log_hv_file = create_hv_log();

You could separate out the nonfunctional changes if you did it in
stages:

 * provide logfile_valid as a dummy macro that tests against -1

 * replace `log_hv_fd' with `log_hv' throughout; replace
   comparisons with -1 with logfile_valid(log_hv); likewise
   client logfiles - no functional change

 * replace log opening code with calls to logfile_open; change
   types; change implementation of logfile_valid

Ian.
diff mbox

Patch

diff --git a/tools/console/daemon/io.c b/tools/console/daemon/io.c
index 7e6a886..228c4af 100644
--- a/tools/console/daemon/io.c
+++ b/tools/console/daemon/io.c
@@ -21,6 +21,7 @@ 
 
 #include "utils.h"
 #include "io.h"
+#include "logfile.h"
 #include <xenevtchn.h>
 #include <xengnttab.h>
 #include <xenstore.h>
@@ -71,7 +72,7 @@  extern int discard_overflowed_data;
 
 static int log_time_hv_needts = 1;
 static int log_time_guest_needts = 1;
-static int log_hv_fd = -1;
+static struct logfile *log_hv_file;
 
 static xengnttab_handle *xgt_handle = NULL;
 
@@ -127,6 +128,15 @@  static int write_all(int fd, const char* buf, size_t len)
 	return 0;
 }
 
+static int write_logfile(struct logfile *logfile, const char *buf,
+			 size_t len)
+{
+	ssize_t r = logfile_append(logfile, buf, len);
+
+	if (r < 0) return -1;
+	return 0;
+}
+
 static int write_with_timestamp(int fd, const char *data, size_t sz,
 				int *needts)
 {
@@ -158,6 +168,38 @@  static int write_with_timestamp(int fd, const char *data, size_t sz,
 	return 0;
 }
 
+static int write_logfile_with_timestamp(struct logfile *logfile,
+					const char *data, size_t sz,
+					int *needts)
+{
+	char ts[32];
+	time_t now = time(NULL);
+	const struct tm *tmnow = localtime(&now);
+	size_t tslen = strftime(ts, sizeof(ts), "[%Y-%m-%d %H:%M:%S] ", tmnow);
+	const char *last_byte = data + sz - 1;
+
+	while (data <= last_byte) {
+		const char *nl = memchr(data, '\n', last_byte + 1 - data);
+		int found_nl = (nl != NULL);
+		if (!found_nl)
+			nl = last_byte;
+
+		if ((*needts && logfile_append(logfile, ts, tslen))
+		    || logfile_append(logfile, data, nl + 1 - data))
+			return -1;
+
+		*needts = found_nl;
+		data = nl + 1;
+		if (found_nl) {
+			// If we printed a newline, strip all \r following it
+			while (data <= last_byte && *data == '\r')
+				data++;
+		}
+	}
+
+	return 0;
+}
+
 static void buffer_append(struct domain *dom)
 {
 	struct buffer *buffer = &dom->buffer;
@@ -265,29 +307,33 @@  static bool domain_is_valid(int domid)
 	return ret;
 }
 
-static int create_hv_log(void)
+static struct logfile *create_hv_log(void)
 {
 	char logfile[PATH_MAX];
-	int fd;
+	struct logfile *tmp;
+
 	snprintf(logfile, PATH_MAX-1, "%s/hypervisor.log", log_dir);
 	logfile[PATH_MAX-1] = '\0';
 
-	fd = open(logfile, O_WRONLY|O_CREAT|O_APPEND, 0644);
-	if (fd == -1)
+	tmp = logfile_new(logfile, 0644);
+
+	if (!tmp)
 		dolog(LOG_ERR, "Failed to open log %s: %d (%s)",
 		      logfile, errno, strerror(errno));
-	if (fd != -1 && log_time_hv) {
-		if (write_with_timestamp(fd, "Logfile Opened\n",
-					 strlen("Logfile Opened\n"),
-					 &log_time_hv_needts) < 0) {
+
+	if (tmp && log_time_hv) {
+		if (write_logfile_with_timestamp(tmp, "Logfile Opened\n",
+						 strlen("Logfile Opened\n"),
+						 &log_time_hv_needts) < 0) {
 			dolog(LOG_ERR, "Failed to log opening timestamp "
-				       "in %s: %d (%s)", logfile, errno,
+				       "in %s: %d (%s)", tmp->basepath, errno,
 				       strerror(errno));
-			close(fd);
-			return -1;
+			logfile_free(tmp);
+			return NULL;
 		}
 	}
-	return fd;
+
+	return tmp;
 }
 
 static int create_domain_log(struct domain *dom)
@@ -929,10 +975,11 @@  static void handle_hv_logs(xenevtchn_handle *xce_handle, bool force)
 			break;
 
 		if (log_time_hv)
-			logret = write_with_timestamp(log_hv_fd, buffer, size,
-						      &log_time_hv_needts);
+			logret = write_logfile_with_timestamp(log_hv_file,
+							      buffer, size,
+							      &log_time_hv_needts);
 		else
-			logret = write_all(log_hv_fd, buffer, size);
+			logret = write_logfile(log_hv_file, buffer, size);
 
 		if (logret < 0)
 			dolog(LOG_ERR, "Failed to write hypervisor log: "
@@ -955,9 +1002,9 @@  static void handle_log_reload(void)
 	}
 
 	if (log_hv) {
-		if (log_hv_fd != -1)
-			close(log_hv_fd);
-		log_hv_fd = create_hv_log();
+		if (log_hv_file)
+			logfile_free(log_hv_file);
+		log_hv_file = create_hv_log();
 	}
 }
 
@@ -1017,8 +1064,8 @@  void handle_io(void)
 			      errno, strerror(errno));
 			goto out;
 		}
-		log_hv_fd = create_hv_log();
-		if (log_hv_fd == -1)
+		log_hv_file = create_hv_log();
+		if (!log_hv_file)
 			goto out;
 		log_hv_evtchn = xenevtchn_bind_virq(xce_handle, VIRQ_CON_RING);
 		if (log_hv_evtchn == -1) {
@@ -1199,9 +1246,9 @@  void handle_io(void)
 	current_array_size = 0;
 
  out:
-	if (log_hv_fd != -1) {
-		close(log_hv_fd);
-		log_hv_fd = -1;
+	if (log_hv_file) {
+		logfile_free(log_hv_file);
+		log_hv_file = NULL;
 	}
 	if (xce_handle != NULL) {
 		xenevtchn_close(xce_handle);