Example of tracing a page-sized read I/O request with ftrace - Prepared for the Xen Project (OPW 2014: http://goo.gl/bcvHMh)

opw-w1-read_test.c

/*
 * Tracing a page-sized read I/O request with ftrace's function_graph tracer.
 * Made up of examples from: https://www.kernel.org/doc/Documentation/trace/ftrace.txt.
 * Prepared for the Xen Project (OPW 2014: http://goo.gl/bcvHMh).
 */

#include <stdio.h>
#include <stdlib.h>
#include <stdarg.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <unistd.h>
#include <string.h>
#include <assert.h>

#define _STR(x) #x
#define STR(x) _STR(x)
#define MAX_PATH 256

const char *find_debugfs(void)
{
       static char debugfs[MAX_PATH+1];
       static int debugfs_found;
       char type[100];
       FILE *fp;

       if (debugfs_found)
               return debugfs;

       if ((fp = fopen("/proc/mounts","r")) == NULL) {
               perror("/proc/mounts");
               return NULL;
       }

       while (fscanf(fp, "%*s %"
                     STR(MAX_PATH)
                     "s %99s %*s %*d %*d\n",
                     debugfs, type) == 2) {
               if (strcmp(type, "debugfs") == 0)
                       break;
       }
       fclose(fp);

       if (strcmp(type, "debugfs") != 0) {
               fprintf(stderr, "debugfs not mounted");
               return NULL;
       }

       strcat(debugfs, "/tracing/");
       debugfs_found = 1;

       return debugfs;
}

const char *tracing_file(const char *file_name)
{
       static char trace_file[MAX_PATH+1];
       snprintf(trace_file, MAX_PATH, "%s/%s", find_debugfs(), file_name);
       return trace_file;
}

void trace_write(const int trace_fd, const char *fmt, ...)
{
	va_list ap;
	char buf[256];
	int n;

	if (trace_fd < 0)
		return;
	va_start(ap, fmt);
	n = vsnprintf(buf, 256, fmt, ap);
	va_end(ap);

	write(trace_fd, buf, n);
}

#define TRACEFILE_CURRENT_TRACER 0
#define TRACEFILE_FTRACE_PID 1
#define TRACEFILE_FTRACE_MARKER 2
#define TRACEFILE_TRACING_ON 3
#define SYSFILE_DROP_CACHES 4
#define SYSFILE_BACKEND 5

#define TRACEFILE_NUM 6

int fds[TRACEFILE_NUM];
unsigned int avail_fd;

int file_avail_fd(const char *fname, const int flags)
{
        assert(fname);
        if ((fds[avail_fd] = open(fname, flags)) < 0) {
                fprintf(stderr, "open() %s failed\n", fname);
                return fds[avail_fd];
        }

        return fds[avail_fd++];
}

int tracing_file_avail_fd(const char *fname, const int flags)
{
        return file_avail_fd(tracing_file(fname), flags);
}

int main(void)
{
        char line[64], *buf;
	unsigned int page_size = getpagesize();
        int s, ret = 0, i;

        if ((buf = malloc(page_size)) == NULL) {
                perror("malloc() failed");
                ret = 1;
                goto out;
        }

        if (tracing_file_avail_fd("current_tracer", O_WRONLY) < 0 ||
            tracing_file_avail_fd("set_ftrace_pid", O_WRONLY) < 0 ||
            tracing_file_avail_fd("trace_marker", O_WRONLY) < 0 ||
            tracing_file_avail_fd("tracing_on", O_WRONLY) < 0 ||
            file_avail_fd("/proc/sys/vm/drop_caches", O_WRONLY) < 0 ||
            file_avail_fd("/dev/sda", O_RDONLY) < 0) {
                ret = 2;
                goto out_close;
        }

        write(fds[TRACEFILE_CURRENT_TRACER], "nop", 4);
        write(fds[TRACEFILE_CURRENT_TRACER], "function_graph", 14);
        s = sprintf(line, "%d\n", getpid());
        write(fds[TRACEFILE_FTRACE_PID], line, s);
        write(fds[SYSFILE_DROP_CACHES], "3", 1);

        write(fds[TRACEFILE_TRACING_ON], "1", 1);
	/* The following will produce a "TRACING START" comment in the trace */
        trace_write(fds[TRACEFILE_FTRACE_MARKER], "TRACING START");

        if (read(fds[SYSFILE_BACKEND], buf, page_size) != page_size) {
                perror("read() failed");
                ret = 3;
        }

        write(fds[TRACEFILE_TRACING_ON], "0", 1);

out_close:
	free(buf);
        for (i = 0 ; i < avail_fd ; i++)
                close(fds[i]);

out:
        return ret;
}