[PATCH 0/3] Add date and domid to guest's console output.

[PATCH 0/3] Add date and domid to guest's console output.

[Yuji Shimada]

These patches add date and domid to guest's console output.

  [PATCH 1/3] Add "--timestamp" option to xenconsole.
  [PATCH 2/3] Add "--console_timestamp" to xm create.
  [PATCH 3/3] Modify stubdom-dm.

We can log guest's console output with date and domid when we create
the guest like below.

 # xm create -c --console_timestamp GUEST > GUEST-console.log

We can check the log after booting the guest.

 # cat GUEST-console.log

   Using config file "./GUEST".
   Started domain GUEST (id=8)
   [2009-01-05 11:01:48 8] mice: PS/2 mouse device common for all mice
   [2009-01-05 11:01:48 8] TCP bic registered
   [2009-01-05 11:01:48 8] NET: Registered protocol family 1
   [2009-01-05 11:01:48 8] NET: Registered protocol family 17
   [2009-01-05 11:01:48 8] Freeing unused kernel memory: 128k freed
   ...

Thanks,
--
Yuji Shimada

[PATCH 1/3] Add "--timestamp" option to xenconsole.

[Yuji Shimada]

This patch adds "--timestamp" and "-t" option to xenconsole.
Xenconsole adds date and domid to output message when it's started
with "--timestamp" or "-t" option.

Thanks,
--
Yuji Shimada

Signed-off-by: Yuji Shimada <shimada-yxb@necst.nec.co.jp>

diff -r af1d9af1a993 tools/console/client/main.c
--- a/tools/console/client/main.c	Wed Jan 21 14:44:43 2009 +0000
+++ b/tools/console/client/main.c	Wed Jan 28 12:01:28 2009 +0900
@@ -41,6 +41,8 @@
 #define ESCAPE_CHARACTER 0x1d
 
 static volatile sig_atomic_t received_signal = 0;
+static int domid;
+static int log_timestamp = 0;
 
 static void sighandler(int signum)
 {
@@ -50,7 +52,7 @@ static bool write_sync(int fd, const voi
 static bool write_sync(int fd, const void *data, size_t size)
 {
 	size_t offset = 0;
-	ssize_t len;
+	ssize_t len = 0;
 
 	while (offset < size) {
 		len = write(fd, data + offset, size - offset);
@@ -58,6 +60,88 @@ static bool write_sync(int fd, const voi
 			return false;
 		}
 		offset += len;
+	}
+	return true;
+}
+
+static bool write_timestamp(int fd)
+{
+	time_t current_tm;
+	struct tm time_str;
+	char date_domid[32];
+
+	time(&current_tm);
+	localtime_r(&current_tm, &time_str);
+	sprintf(date_domid, "[%4d-%.2d-%.2d %.2d:%.2d:%.2d %d] ",
+	        time_str.tm_year+1900, time_str.tm_mon+1,
+	        time_str.tm_mday, time_str.tm_hour, time_str.tm_min,
+	        time_str.tm_sec, domid);
+	if (write(fd, &date_domid, strlen(date_domid)) < 1) {
+		return false;
+	}
+
+	return true;
+}
+
+static bool write_sync_with_timestamp(int fd, const void *buf, size_t size)
+{
+	size_t offset = 0;
+	ssize_t len = 0;
+	char *data = (char *)buf;
+	size_t cur_offset;
+	static char last_newline = 0;
+	static int timestamp_f = 1; /* flag for timestamp */
+
+	while (offset < size) {
+		for (cur_offset = offset; cur_offset < size; cur_offset++) {
+			if (data[cur_offset] == '\r' ||
+			    data[cur_offset] == '\n') {
+				break;
+			}
+		}
+		len = cur_offset - offset;
+		if (timestamp_f == 1 && (len > 0 || last_newline == 0 ||
+		    data[cur_offset] == last_newline)) {
+			if (write_timestamp(fd) == false) {
+				return false;
+			}
+			timestamp_f = 0;
+		}
+		if (len > 0) {
+			len = write(fd, data + offset, len);
+			if (len < 1) {
+				return false;
+			}
+			last_newline = 0;
+			offset += len;
+			if (size <= offset) {
+				break;
+			}
+		}
+		if (data[offset] == '\n' || data[offset] == '\r') {
+			if (last_newline == 0 ||
+			    data[offset] == last_newline) {
+				timestamp_f = 1;
+				last_newline = data[offset];
+				if (isatty(fd)) {
+					if (write(fd, data + offset, 1) != 1) {
+						return false;
+					}
+				} else {
+					if (write(fd, "\n", 1) != 1) {
+						return false;
+					}
+				}
+			} else {
+				last_newline = 0;
+				if (isatty(fd)) {
+					if (write(fd, data + offset, 1) != 1) {
+						return false;
+					}
+				}
+			}
+			offset++;
+		}
 	}
 
 	return true;
@@ -68,6 +152,7 @@ static void usage(const char *program) {
 	       "Attaches to a virtual domain console\n"
 	       "\n"
 	       "  -h, --help       display this help and exit\n"
+	       "  -t, --timestamp       add timestamp to output message\n"
 	       , program);
 }
 
@@ -199,9 +284,17 @@ static int console_loop(int fd, struct x
 				continue;
 			}
 
-			if (!write_sync(STDOUT_FILENO, msg, len)) {
-				perror("write() failed");
-				return -1;
+			if (log_timestamp) {
+				if (!write_sync_with_timestamp(STDOUT_FILENO,
+				                               msg, len)) {
+					perror("write() failed");
+					return -1;
+				}
+			} else {
+				if (!write_sync(STDOUT_FILENO, msg, len)) {
+					perror("write() failed");
+					return -1;
+				}
 			}
 		}
 	} while (received_signal == 0);
@@ -212,12 +305,12 @@ int main(int argc, char **argv)
 int main(int argc, char **argv)
 {
 	struct termios attr;
-	int domid;
-	char *sopt = "h";
+	char *sopt = "ht";
 	int ch;
 	int opt_ind=0;
 	struct option lopt[] = {
 		{ "help",    0, 0, 'h' },
+		{ "timestamp", 0, 0, 't' },
 		{ 0 },
 
 	};
@@ -231,6 +324,9 @@ int main(int argc, char **argv)
 		case 'h':
 			usage(argv[0]);
 			exit(0);
+			break;
+		case 't':
+			log_timestamp = 1;
 			break;
 		}
 	}

[PATCH 2/3] Add "--console_timestamp" to xm create.

[Yuji Shimada]

This patch adds "--console_timestamp" option to xm create.
Xenconsole adds date and domid to output message when we create a
guest with "--console_timestamp" option of xm create.

 # xm create -c --console_timestamp GUEST

This patch also adds "--timestamp" option to xm console.
Xenconsole adds date and domid to output message when we attach
guest's console with "--timestamp" option of xm console.

 # xm console --timestamp

Thanks,
--
Yuji Shimada

Signed-off-by: Yuji Shimada <shimada-yxb@necst.nec.co.jp>

diff -r af1d9af1a993 tools/python/xen/xm/console.py
--- a/tools/python/xen/xm/console.py	Wed Jan 21 14:44:43 2009 +0000
+++ b/tools/python/xen/xm/console.py	Mon Jan 26 12:04:35 2009 +0900
@@ -27,6 +27,8 @@ def execConsole(domid):
 def execConsole(domid):
     xen.util.auxbin.execute(XENCONSOLE, [str(domid)])
 
+def execConsoleTimestamp(domid):
+    xen.util.auxbin.execute(XENCONSOLE, ['--timestamp', str(domid)])
 
 class OurXenstoreConnection:
     def __init__(self):
diff -r af1d9af1a993 tools/python/xen/xm/create.py
--- a/tools/python/xen/xm/create.py	Wed Jan 21 14:44:43 2009 +0000
+++ b/tools/python/xen/xm/create.py	Mon Jan 26 12:04:37 2009 +0900
@@ -120,6 +120,10 @@ gopts.opt('console_autoconnect', short='
 gopts.opt('console_autoconnect', short='c',
           fn=set_true, default=0,
           use="Connect to the console after the domain is created.")
+
+gopts.opt('console_timestamp',
+          fn=set_true, default=0,
+          use="Add timestamp to output message.")
 
 gopts.opt('vncviewer',
           fn=set_true, default=0,
@@ -1352,7 +1356,10 @@ def do_console(domain_name):
                     sys.exit(os.WEXITSTATUS(rv))
             try:
                 domid = domain_name_to_domid(domain_name)
-                console.execConsole(domid)
+                if gopts.vals.console_timestamp:
+                    console.execConsoleTimestamp(domid)
+                else:
+                    console.execConsole(domid)
             except:
                 pass
         print("Could not start console\n");
diff -r af1d9af1a993 tools/python/xen/xm/main.py
--- a/tools/python/xen/xm/main.py	Wed Jan 21 14:44:43 2009 +0000
+++ b/tools/python/xen/xm/main.py	Mon Jan 26 12:04:38 2009 +0900
@@ -248,6 +248,7 @@ SUBCOMMAND_OPTIONS = {
     ),
     'console': (
        ('-q', '--quiet', 'Do not print an error message if the domain does not exist'),
+       ('', '--timestamp', 'Add timestamp to output message'),
     ),
     'vncviewer': (
        ('', '--autopass', 'Pass VNC password to viewer via stdin and -autopass'),
@@ -270,6 +271,7 @@ SUBCOMMAND_OPTIONS = {
     'start': (
        ('-p', '--paused', 'Do not unpause domain after starting it'),
        ('-c', '--console_autoconnect', 'Connect to the console after the domain is created'),
+       ('', '--console_timestamp', 'Add timestamp to output message'),
        ('', '--vncviewer', 'Connect to display via VNC after the domain is created'),
        ('', '--vncviewer-autopass', 'Pass VNC password to viewer via stdin and -autopass'),
     ),
@@ -1189,7 +1191,10 @@ def start_do_console(domain_name):
                 else:
                     dom = server.xend.domain(domain_name)
                     domid = int(sxp.child_value(dom, 'domid', '-1'))
-                console.execConsole(domid)
+                if console_timestamp == True:
+                    console.execConsoleTimestamp(domid)
+                else:
+                    console.execConsole(domid)
             except:
                 pass
         print("Could not start console\n");
@@ -1199,16 +1204,19 @@ def xm_start(args):
 
     paused = False
     console_autoconnect = False
+    console_timestamp = False
     vncviewer = False
     vncviewer_autopass = False
 
     try:
-        (options, params) = getopt.gnu_getopt(args, 'cp', ['console_autoconnect','paused','vncviewer','vncviewer-autopass'])
+        (options, params) = getopt.gnu_getopt(args, 'cp', ['console_autoconnect','console_timestamp','paused','vncviewer','vncviewer-autopass'])
         for (k, v) in options:
             if k in ('-p', '--paused'):
                 paused = True
             if k in ('-c', '--console_autoconnect'):
                 console_autoconnect = True
+            if k in ('--console_timestamp'):
+                console_timestamp = True
             if k in ('--vncviewer'):
                 vncviewer = True
             if k in ('--vncviewer-autopass'):
@@ -1767,9 +1775,10 @@ def xm_console(args):
     arg_check(args, "console", 1, 2)
 
     quiet = False;
+    timestamp = False;
 
     try:
-        (options, params) = getopt.gnu_getopt(args, 'q', ['quiet'])
+        (options, params) = getopt.gnu_getopt(args, 'q', ['quiet','timestamp'])
     except getopt.GetoptError, opterr:
         err(opterr)
         usage('console')
@@ -1777,6 +1786,8 @@ def xm_console(args):
     for (k, v) in options:
         if k in ['-q', '--quiet']:
             quiet = True
+        elif k in ['', '--timestamp']:
+            timestamp = True
         else:
             assert False
 
@@ -1804,7 +1815,10 @@ def xm_console(args):
         else:
             raise xmlrpclib.Fault(0, "Domain '%s' is not started" % dom)
 
-    console.execConsole(domid)
+    if timestamp == True:
+        console.execConsoleTimestamp(domid)
+    else:
+        console.execConsole(domid)
 
 
 def domain_name_to_domid(domain_name):

[PATCH 3/3] Modify stubdom-dm.

[Yuji Shimada]

This patch modifies stubdom-dm to use "--console_timestamp" option of
xm create.

We can add date and domid to stubdom's log with this patch.

  # xm create CentOS-Stub

  # cat /var/log/xen/qemu-dm-CentOS-Stub.log 

    Using config file "/etc/xen/CentOS-Stub-dm".
    Started domain CentOS-Stub-dm (id=2)
    [2009-01-05 10:57:20 2] xs_read_watch() -> /local/domain/0/device-model/1/command dm-command
    [2009-01-05 10:57:20 2] xs_read(/local/domain/0/device-model/1/command): ENOENT
    [2009-01-05 10:57:20 2] resize to 720x400@0, 0 required
    [2009-01-05 10:57:20 2] xs_read_watch() -> /local/domain/0/device-model/1/logdirty/next-active logdirty
    [2009-01-05 10:57:20 2] xs_read(/local/domain/0/device-model/1/logdirty/key): ENOENT
    [2009-01-05 10:57:20 2] I/O request not ready: 0, ptr: 0, port: e9, data: a, count: 1, size: 1
    [2009-01-05 10:57:20 2] ******************* FBFRONT for /local/domain/2/device/vfb/0 **********
    [2009-01-05 10:57:20 2] 
    [2009-01-05 10:57:20 2] 
    [2009-01-05 10:57:20 2] /local/domain/0/backend/vkbd/2/0 connected
    [2009-01-05 10:57:20 2] backend at /local/domain/0/backend/vfb/2/0
    ...

I know qemu's log will have timestamp function in the future.
When qemu comes to output timestamp by itself, please remove this patch.

Thanks,
--
Yuji Shimada

Signed-off-by: Yuji Shimada <shimada-yxb@necst.nec.co.jp>

diff -r af1d9af1a993 stubdom/stubdom-dm
--- a/stubdom/stubdom-dm	Wed Jan 21 14:44:43 2009 +0000
+++ b/stubdom/stubdom-dm	Mon Jan 26 12:04:08 2009 +0900
@@ -72,7 +72,7 @@ do
 	sleep 1
 done
 
-creation="xm create -c $domname-dm target=$domid memory=32 extra=\"$extra\""
+creation="xm create -c --console_timestamp $domname-dm target=$domid memory=32 extra=\"$extra\""
 
 (while true ; do sleep 60 ; done) | /bin/sh -c "$creation" &
 #xterm -geometry +0+0 -e /bin/sh -c "$creation ; echo ; echo press ENTER to shut down ; read" &

Re: [PATCH 0/3] Add date and domid to guest's console output.

[Daniel P. Berrange]

On Wed, Jan 28, 2009 at 01:33:12PM +0900, Yuji Shimada wrote:
> These patches add date and domid to guest's console output.
> 
>   [PATCH 1/3] Add "--timestamp" option to xenconsole.
>   [PATCH 2/3] Add "--console_timestamp" to xm create.
>   [PATCH 3/3] Modify stubdom-dm.
> 
> We can log guest's console output with date and domid when we create
> the guest like below.
> 
>  # xm create -c --console_timestamp GUEST > GUEST-console.log

This seems like a slightly odd place in the code to address the problem.

The xenconsoled daemon has the ability to save all guest data to a logfile
in /var/log/xen/console/guest-$NAME.log. So if you want to save logs and
timestamp them, it'd seem more natural to put timestamping capability in
the xenconsoled program.

Of course this only handles paravirt console. For fullvirt guests, if you
wanted to timestamp the serial console output, then something would need
to be done with QEMU - or perhaps get QEMU to feed the serial data to the
xenconsoled program for logging to disk ? 

Daniel
-- 
|: Red Hat, Engineering, London   -o-   http://people.redhat.com/berrange/ :|
|: http://libvirt.org  -o-  http://virt-manager.org  -o-  http://ovirt.org :|
|: http://autobuild.org       -o-         http://search.cpan.org/~danberr/ :|
|: GnuPG: 7D3B9505  -o-  F3C9 553F A1DA 4AC2 5648 23C1 B3DF F742 7D3B 9505 :|

Re: [PATCH 0/3] Add date and domid to guest's console output.

[Yuji Shimada]

On Wed, 28 Jan 2009 11:04:48 +0000
"Daniel P. Berrange" <berrange@redhat.com> wrote:

> On Wed, Jan 28, 2009 at 01:33:12PM +0900, Yuji Shimada wrote:
> > These patches add date and domid to guest's console output.
> > 
> >   [PATCH 1/3] Add "--timestamp" option to xenconsole.
> >   [PATCH 2/3] Add "--console_timestamp" to xm create.
> >   [PATCH 3/3] Modify stubdom-dm.
> > 
> > We can log guest's console output with date and domid when we create
> > the guest like below.
> > 
> >  # xm create -c --console_timestamp GUEST > GUEST-console.log
> 
> This seems like a slightly odd place in the code to address the problem.
> 
> The xenconsoled daemon has the ability to save all guest data to a logfile
> in /var/log/xen/console/guest-$NAME.log. So if you want to save logs and
> timestamp them, it'd seem more natural to put timestamping capability in
> the xenconsoled program.
> 

Hi Daniel,

Thanks for your comment.

xenconsoled saves all guest's logs.
On the other hand, my patch saves one guest's log with timestamp.

So my patch is useful when we need particular guest's log with
timestamp.

--
Yuji Shimada

Re: [PATCH 0/3] Add date and domid to guest's console output.

[Yuji Shimada]

> On Wed, 28 Jan 2009 11:04:48 +0000
> "Daniel P. Berrange" <berrange@redhat.com> wrote:
> 
> > On Wed, Jan 28, 2009 at 01:33:12PM +0900, Yuji Shimada wrote:
> > > These patches add date and domid to guest's console output.
> > > 
> > >   [PATCH 1/3] Add "--timestamp" option to xenconsole.
> > >   [PATCH 2/3] Add "--console_timestamp" to xm create.
> > >   [PATCH 3/3] Modify stubdom-dm.
> > > 
> > > We can log guest's console output with date and domid when we create
> > > the guest like below.
> > > 
> > >  # xm create -c --console_timestamp GUEST > GUEST-console.log
> > 
> > This seems like a slightly odd place in the code to address the problem.
> > 
> > The xenconsoled daemon has the ability to save all guest data to a logfile
> > in /var/log/xen/console/guest-$NAME.log. So if you want to save logs and
> > timestamp them, it'd seem more natural to put timestamping capability in
> > the xenconsoled program.
> > 
> 
> Hi Daniel,
> 
> Thanks for your comment.
> 
> xenconsoled saves all guest's logs.
> On the other hand, my patch saves one guest's log with timestamp.
> 
> So my patch is useful when we need particular guest's log with
> timestamp.
> 
> --
> Yuji Shimada

Hi Daniel,

Did you see my comment?
Do you feel it's odd place yet?

I believe my patch is reasonable.
Because we can get particular guest's log with timestamp.

If there're any complaints, please let me known.

--
Yuji Shimada

Re: [PATCH 0/3] Add date and domid to guest's console output.

[Ian Jackson]

Yuji Shimada writes ("Re: [Xen-devel] [PATCH 0/3] Add date and domid to guest's console output."):
> Did you see my comment?
> Do you feel it's odd place yet?

I'm afraid I still agree with Daniel.

> I believe my patch is reasonable.
> Because we can get particular guest's log with timestamp.

Surely it would be best just to have xenconsoled always timestamp all
of its logs when it writes them to files.  I haven't looked at its
configuration but I presume it can be made to tag them with particular
guest names (and if not it should be made to).

Ian.