Linux Virtualization - Aug 2012 - [PATCH 0/5] trace-cmd: Add a recorder readable feature for virtio-trace

Hi Steven,

The following patch set provides a feature which can read trace data of a guest
using virtio-trace (https://lkml.org/lkml/2012/8/9/210) for a recorder
function of trace-cmd. This patch set depends on the trace-agent running on a
guest in the virtio-trace system.

To translate raw data of a guest to text data on a host, information of debugfs
in the guest is also needed on the host. In other words, the guest's debugfs
must be exposed (mounted) on the host via other serial line (we don't like
to
depend on network connection). For this purpose, we'll use DIOD 9pfs server
(http://code.google.com/p/diod/) as below.

***HOW TO USE***
We explain about how to translate raw data to text data on a host using
trace-cmd applied this patch set and virtio-trace.

- Preparation
1. Make FIFO in a host
 virtio-trace uses virtio-serial pipe as trace data paths as to the number
of CPUs and a control path, so FIFO (named pipe) should be created as follows:
        # mkdir /tmp/virtio-trace/
        # mkfifo /tmp/virtio-trace/trace-path-cpu{0,1,2,...,X}.{in,out}
        # mkfifo /tmp/virtio-trace/agent-ctl-path.{in,out}

Here, if we assign 1VCPU for a guest, then we set as follows:
        trace-path-cpu0.{in.out}
and
        agent-ctl-path.{in,out}.

2. Set up of virtio-serial pipe and unix in a host
 Add qemu option to use virtio-serial pipe for tracing and unix for debugfs.

 ##virtio-serial device##
     -device virtio-serial-pci,id=virtio-serial0\
 ##control path##
     -chardev pipe,id=charchannel0,path=/tmp/virtio-trace/agent-ctl-path\
     -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,\
      id=channel0,name=agent-ctl-path\
 ##data path##
     -chardev pipe,id=charchannel1,path=/tmp/virtio-trace/trace-path-cpu0\
     -device virtserialport,bus=virtio-serial0.0,nr=2,chardev=charchannel1,\
      id=channel1,name=trace-path-cpu0\
 ##9pfs path##
     -device virtio-serial \
     -chardev socket,path=/tmp/virtio-trace/trace-9pfs,server,nowait, \
      id=trace-9pfs \
     -device virtserialport,chardev=trace-9pfs,name=virtioserial

If you manage guests with libvirt, add the following tags to domain XML files.
Then, libvirt passes the same command option to qemu.

        <channel type='pipe'>
           <source path='/tmp/virtio-trace/agent-ctl-path'/>
           <target type='virtio' name='agent-ctl-path'/>
           <address type='virtio-serial' controller='0'
bus='0' port='0'/>
        </channel>
        <channel type='pipe'>
           <source path='/tmp/virtio-trace/trace-path-cpu0'/>
           <target type='virtio' name='trace-path-cpu0'/>
           <address type='virtio-serial' controller='0'
bus='0' port='1'/>
        </channel>
	<channel type='unix'>
           <source mode='bind'
path='/tmp/virtio-trace/trace-9pfs'/>
           <target type='virtio' name='trace-9pfs'/>
           <address type='virtio-serial' controller='0'
bus='0' port='2'/>
        </channel>
Here, chardev names are restricted to trace-path-cpu0 and agent-ctl-path. UNIX
domain socket is automatically created on a host.

3. Boot the guest
 You can find some chardev in /dev/virtio-ports/ in the guest.

4. Create symbolic link for trace-cmd on the host
	# ln -s /tmp/virtio-trace/trace-path-cpu0.out \
	  /tmp/virtio-tracing/tracing/per_cpu/cpu0/trace_pipe_raw

5. Wait for 9pfs server on the host
	# mount -t 9p -o trans=unix,access=any,uname=root, \
	  aname=/sys/kernel/debug,version=9p2000.L \
	  /tmp/virtio-trace/trace-9pfs /tmp/virtio-trace/debugfs

6. Run DIOD on the guest
	# diod -E -Nn -u 0

7. Connect DIOD to virtio-console on the guest
	# socat TCP4:127.0.0.1:564 /dev/virtio-ports/trace-9pfs

- Execution
1. Run trace-agent on the guest
	# ./trace-agent

2. Execute trace-cmd on the host
	# AGENT_READ_DIR=/tmp/virtio-trace/tracing \
	  AGENT_CTL=/tmp/virtio-trace/agent-ctl-path.in \
	  TRACE_DIR=/tmp/virtio-trace/debugfs/tracing \
	  ./trace-cmd record -e "sched:*

3. Translate raw data to text data on the host
	# ./trace-cmd report trace.dat

***Just enhancement ideas***
 - Support for trace-cmd => done
 - Support for 9pfs protocol
 - Support for non-blocking mode in QEMU

Thank you,

---

Masami Hiramatsu (2):
      trace-cmd: Use tracing directory to count CPUs
      trace-cmd: Use TRACE_DIR envrionment variable if defined

Yoshihiro YUNOMAE (3):
      trace-cmd: Use polling function
      trace-cmd: Add non-blocking option for open() and splice_read()
      trace-cmd: Support trace-agent of virtio-trace


 trace-cmd.h      |    1 
 trace-record.c   |   41 ++++++++++++++++++++
 trace-recorder.c |  112 ++++++++++++++++++++++++++++++++++++++++++++++++------
 trace-util.c     |   27 +++++++++++++
 4 files changed, 169 insertions(+), 12 deletions(-)

-- 
Yoshihiro YUNOMAE
Software Platform Research Dept. Linux Technology Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: yoshihiro.yunomae.ez at hitachi.com

From: Masami Hiramatsu <masami.hiramatsu.pt at hitachi.com>

Use TRACE_DIR environment variable for setting
debugfs/tracing directory if defined. This is
for controlling guest(or remote) ftrace.

Signed-off-by: Masami Hiramatsu <masami.hiramatsu.pt at hitachi.com>
Signed-off-by: Yoshihiro YUNOMAE <yoshihiro.yunomae.ez at hitachi.com>
---

 trace-util.c |    9 +++++++++
 1 files changed, 9 insertions(+), 0 deletions(-)

diff --git a/trace-util.c b/trace-util.c
index e128188..d5a3eb4 100644
--- a/trace-util.c
+++ b/trace-util.c
@@ -311,6 +311,15 @@ char *tracecmd_find_tracing_dir(void)
 	char type[100];
 	FILE *fp;
 	
+	tracing_dir = getenv("TRACE_DIR");
+	if (tracing_dir) {
+		tracing_dir = strdup(tracing_dir);
+		if (!tracing_dir)
+			die("malloc");
+		warning("Use environmental tracing directory: %s\n", tracing_dir);
+		return tracing_dir;
+	}
+
 	if ((fp = fopen("/proc/mounts","r")) == NULL) {
 		warning("Can't open /proc/mounts for read");
 		return NULL;

From: Masami Hiramatsu <masami.hiramatsu.pt at hitachi.com>

Count debugfs/tracing/per_cpu/cpu* to determine the
number of CPUs.

Signed-off-by: Masami Hiramatsu <masami.hiramatsu.pt at hitachi.com>
Signed-off-by: Yoshihiro YUNOMAE <yoshihiro.yunomae.ez at hitachi.com>
---

 trace-record.c |   41 +++++++++++++++++++++++++++++++++++++++++
 1 files changed, 41 insertions(+), 0 deletions(-)

diff --git a/trace-record.c b/trace-record.c
index 9dc18a9..ed18951 100644
--- a/trace-record.c
+++ b/trace-record.c
@@ -1179,6 +1179,41 @@ static void expand_event_list(void)
 	}
 }
 
+static int count_tracingdir_cpus(void)
+{
+	char *tracing_dir = NULL;
+	char *percpu_dir = NULL;
+	struct dirent **namelist;
+	int count = 0, n;
+
+	/* Count cpus in per_cpu directory */
+	tracing_dir = tracecmd_find_tracing_dir();
+	if (!tracing_dir)
+		return 0;
+	percpu_dir = malloc_or_die(strlen(tracing_dir) + 9);
+	if (!percpu_dir)
+		goto err;
+
+	sprintf(percpu_dir, "%s/per_cpu", tracing_dir);
+
+	n = scandir(percpu_dir, &namelist, NULL, alphasort);
+	if (n > 0) {
+		while (n--) {
+			if (strncmp("cpu", namelist[n]->d_name, 3) == 0)
+				count++;
+			free(namelist[n]);
+		}
+		free(namelist);
+	}
+
+	if (percpu_dir)
+		free(percpu_dir);
+err:
+	if (tracing_dir)
+		free(tracing_dir);
+	return count;
+}
+
 static int count_cpus(void)
 {
 	FILE *fp;
@@ -1189,6 +1224,12 @@ static int count_cpus(void)
 	size_t n;
 	int r;
 
+	cpus = count_tracingdir_cpus();
+	if (cpus > 0)
+		return cpus;
+
+	warning("failed to use tracing_dir to determine number of CPUS");
+
 	cpus = sysconf(_SC_NPROCESSORS_CONF);
 	if (cpus > 0)
 		return cpus;

Add read path and control path to use trace-agent of virtio-trace.
When we use trace-agent, trace-cmd will be used as follows:
	# AGENT_READ_DIR=/tmp/virtio-trace/tracing \
	  AGENT_CTL=/tmp/virtio-trace/agent-ctl-path.in \
	  TRACING_DIR=/tmp/virtio-trace/debugfs/tracing \
	  trace-cmd record -e "sched:*"
Here, AGENT_READ_DIR is the path for a reading directory of virtio-trace,
AGENT_CTL is a control path of trace-agent, and TRACING_DIR is a debugfs path
of a guest.

Signed-off-by: Yoshihiro YUNOMAE <yoshihiro.yunomae.ez at hitachi.com>
---

 trace-cmd.h      |    1 +
 trace-recorder.c |   57 +++++++++++++++++++++++++++++++++++++++++++++++++++++-
 trace-util.c     |   18 +++++++++++++++++
 3 files changed, 75 insertions(+), 1 deletions(-)

diff --git a/trace-cmd.h b/trace-cmd.h
index f904dc5..75506ed 100644
--- a/trace-cmd.h
+++ b/trace-cmd.h
@@ -72,6 +72,7 @@ static inline int tracecmd_host_bigendian(void)
 }
 
 char *tracecmd_find_tracing_dir(void);
+char *guest_agent_tracing_read_dir(void);
 
 /* --- Opening and Reading the trace.dat file --- */
 
diff --git a/trace-recorder.c b/trace-recorder.c
index 215affc..3b750e9 100644
--- a/trace-recorder.c
+++ b/trace-recorder.c
@@ -33,6 +33,7 @@
 #include <unistd.h>
 #include <ctype.h>
 #include <errno.h>
+#include <stdbool.h>
 
 #include "trace-cmd.h"
 
@@ -43,6 +44,8 @@ struct tracecmd_recorder {
 	int		page_size;
 	int		cpu;
 	int		stop;
+	int		ctl_fd;
+	bool		agent_existing;
 };
 
 void tracecmd_free_recorder(struct tracecmd_recorder *recorder)
@@ -59,11 +62,29 @@ void tracecmd_free_recorder(struct tracecmd_recorder
*recorder)
 	free(recorder);
 }
 
+static char *use_trace_agent_dir(char *ctl_path,
+					struct tracecmd_recorder *recorder)
+{
+	ctl_path = strdup(ctl_path);
+	if (!ctl_path)
+		die("malloc");
+	warning("Use environmental control path: %s\n", ctl_path);
+
+	recorder->ctl_fd = open(ctl_path, O_WRONLY);
+	if (recorder->ctl_fd < 0)
+		return NULL;
+
+	recorder->agent_existing = true;
+
+	return guest_agent_tracing_read_dir();
+}
+
 struct tracecmd_recorder *tracecmd_create_recorder_fd(int fd, int cpu)
 {
 	struct tracecmd_recorder *recorder;
 	char *tracing = NULL;
 	char *path = NULL;
+	char *ctl_path = NULL;
 	int ret;
 
 	recorder = malloc_or_die(sizeof(*recorder));
@@ -76,12 +97,23 @@ struct tracecmd_recorder *tracecmd_create_recorder_fd(int
fd, int cpu)
 	recorder->trace_fd = -1;
 	recorder->brass[0] = -1;
 	recorder->brass[1] = -1;
+	recorder->ctl_fd = -1;
+	recorder->agent_existing = false;
 
 	recorder->page_size = getpagesize();
 
 	recorder->fd = fd;
 
-	tracing = tracecmd_find_tracing_dir();
+	/*
+	 * The trace-agent on a guest is controlled to run or stop by a host,
+	 * so we need to assign the control path of the trace-agent to use
+	 * virtio-trace.
+	 */
+	ctl_path = getenv("AGENT_CTL");
+	if (ctl_path)
+		tracing = use_trace_agent_dir(ctl_path, recorder);
+	else
+		tracing = tracecmd_find_tracing_dir();
 	if (!tracing) {
 		errno = ENODEV;
 		goto out_free;
@@ -182,6 +214,24 @@ long tracecmd_flush_recording(struct tracecmd_recorder
*recorder)
 	return total;
 }
 
+static void operation_to_trace_agent(int ctl_fd, bool run_agent)
+{
+	if (run_agent == true)
+		write(ctl_fd, "1", 2);
+	else
+		write(ctl_fd, "0", 2);
+}
+
+static void run_operation_to_trace_agent(int ctl_fd)
+{
+	operation_to_trace_agent(ctl_fd, true);
+}
+
+static void stop_operation_to_trace_agent(int ctl_fd)
+{
+	operation_to_trace_agent(ctl_fd, false);
+}
+
 int tracecmd_start_recording(struct tracecmd_recorder *recorder, unsigned long
sleep)
 {
 	struct timespec req;
@@ -189,6 +239,9 @@ int tracecmd_start_recording(struct tracecmd_recorder
*recorder, unsigned long s
 
 	recorder->stop = 0;
 
+	if (recorder->agent_existing)
+		run_operation_to_trace_agent(recorder->ctl_fd);
+	
 	do {
 		if (sleep) {
 			req.tv_sec = sleep / 1000000;
@@ -214,6 +267,8 @@ void tracecmd_stop_recording(struct tracecmd_recorder
*recorder)
 	if (!recorder)
 		return;
 
+	if (recorder->agent_existing)
+		stop_operation_to_trace_agent(recorder->ctl_fd);
 	recorder->stop = 1;
 }
 
diff --git a/trace-util.c b/trace-util.c
index d5a3eb4..ff639be 100644
--- a/trace-util.c
+++ b/trace-util.c
@@ -304,6 +304,24 @@ static int mount_debugfs(void)
 	return ret;
 }
 
+char *guest_agent_tracing_read_dir(void)
+{
+	char *tracing_read_dir;
+
+	tracing_read_dir = getenv("AGENT_READ_DIR");
+	if (tracing_read_dir) {
+		tracing_read_dir = strdup(tracing_read_dir);
+		if (!tracing_read_dir)
+			die("malloc");
+		warning("Use environmental read directory of trace-agent: %s\n",
+							tracing_read_dir);
+		return tracing_read_dir;
+	}
+
+	warning("AGENT_READ_DIR was not declared");
+	return NULL;
+}
+
 char *tracecmd_find_tracing_dir(void)
 {
 	char debugfs[MAX_PATH+1];

Add non-blocking option for open() and splice_read() for avoiding block to read
trace data of a guest from FIFO.

If SIGINT comes to read/write processes from the parent process in the case
where FIFO as a read I/F is assigned, then reading is normally blocked for
splice_read(). So, we added nonblock option to open() and splice_read().

Signed-off-by: Yoshihiro YUNOMAE <yoshihiro.yunomae.ez at hitachi.com>
---

 trace-recorder.c |   13 ++++++++-----
 1 files changed, 8 insertions(+), 5 deletions(-)

diff --git a/trace-recorder.c b/trace-recorder.c
index 3b750e9..6577fe8 100644
--- a/trace-recorder.c
+++ b/trace-recorder.c
@@ -124,7 +124,7 @@ struct tracecmd_recorder *tracecmd_create_recorder_fd(int
fd, int cpu)
 		goto out_free;
 
 	sprintf(path, "%s/per_cpu/cpu%d/trace_pipe_raw", tracing, cpu);
-	recorder->trace_fd = open(path, O_RDONLY);
+	recorder->trace_fd = open(path, O_RDONLY | O_NONBLOCK);
 	if (recorder->trace_fd < 0)
 		goto out_free;
 
@@ -172,14 +172,17 @@ static long splice_data(struct tracecmd_recorder
*recorder)
 	long ret;
 
 	ret = splice(recorder->trace_fd, NULL, recorder->brass[1], NULL,
-		     recorder->page_size, 1 /* SPLICE_F_MOVE */);
+		     recorder->page_size, SPLICE_F_MOVE | SPLICE_F_NONBLOCK);
 	if (ret < 0) {
-		warning("recorder error in splice input");
-		return -1;
+		if (errno != EAGAIN) {
+			warning("recorder error in splice input");
+			return -1;
+		}
+		return 0; /* Buffer is empty */
 	}
 
 	ret = splice(recorder->brass[0], NULL, recorder->fd, NULL,
-		     recorder->page_size, 3 /* and NON_BLOCK */);
+		     recorder->page_size, SPLICE_F_MOVE | SPLICE_F_NONBLOCK);
 	if (ret < 0) {
 		if (errno != EAGAIN) {
 			warning("recorder error in splice output");

Use poll() for avoiding a busy loop to read trace data of a guest from FIFO.

Signed-off-by: Yoshihiro YUNOMAE <yoshihiro.yunomae.ez at hitachi.com>
---

 trace-recorder.c |   42 ++++++++++++++++++++++++++++++++++++------
 1 files changed, 36 insertions(+), 6 deletions(-)

diff --git a/trace-recorder.c b/trace-recorder.c
index 6577fe8..bdf9798 100644
--- a/trace-recorder.c
+++ b/trace-recorder.c
@@ -34,9 +34,12 @@
 #include <ctype.h>
 #include <errno.h>
 #include <stdbool.h>
+#include <poll.h>
 
 #include "trace-cmd.h"
 
+#define WAIT_MSEC 1
+
 struct tracecmd_recorder {
 	int		fd;
 	int		trace_fd;
@@ -235,9 +238,37 @@ static void stop_operation_to_trace_agent(int ctl_fd)
 	operation_to_trace_agent(ctl_fd, false);
 }
 
-int tracecmd_start_recording(struct tracecmd_recorder *recorder, unsigned long
sleep)
+static int wait_data(struct tracecmd_recorder *recorder, unsigned long sleep)
 {
+	struct pollfd poll_fd;
 	struct timespec req;
+	int ret = 0;
+
+	if (recorder->agent_existing) {
+		poll_fd.fd = recorder->trace_fd;
+		poll_fd.events = POLLIN;
+		while (1) {
+			ret = poll(&poll_fd, 1, WAIT_MSEC);
+
+			if(ret < 0) {
+				warning("polling error");
+				return ret;
+			}
+
+			if (ret)
+				break;
+		}
+	} else if (sleep) {
+		req.tv_sec = sleep / 1000000;
+		req.tv_nsec = (sleep % 1000000) * 1000;
+		nanosleep(&req, NULL);
+	}
+
+	return ret;
+}
+
+int tracecmd_start_recording(struct tracecmd_recorder *recorder, unsigned long
sleep)
+{
 	long ret;
 
 	recorder->stop = 0;
@@ -246,11 +277,10 @@ int tracecmd_start_recording(struct tracecmd_recorder
*recorder, unsigned long s
 		run_operation_to_trace_agent(recorder->ctl_fd);
 	
 	do {
-		if (sleep) {
-			req.tv_sec = sleep / 1000000;
-			req.tv_nsec = (sleep % 1000000) * 1000;
-			nanosleep(&req, NULL);
-		}
+		ret = wait_data(recorder, sleep);
+		if (ret < 0)
+			return ret;
+
 		ret = splice_data(recorder);
 		if (ret < 0)
 			return ret;