[sysprof/ftrace: 1/16] Beginning of support for ftrace

[Søren Sandmann Pedersen <ssp src gnome org>]

commit 6a874697d0ac0dab27b04fe75104632a69206605
Author: Soren Sandmann <sandmann daimi au dk>
Date:   Sat May 10 19:05:29 2008 +0000

    Beginning of support for ftrace

 collector.c  |  431 ++++++++++++++++++++++++++++++++++++++++++++++++++--------
 collector.h  |    2 +
 configure.ac |    4 +-
 process.c    |   16 ++-
 process.h    |    2 +-
 sysprof.c    |   16 ++
 6 files changed, 402 insertions(+), 69 deletions(-)
---
diff --git a/collector.c b/collector.c
index ce18e47..37e4a5d 100644
--- a/collector.c
+++ b/collector.c
@@ -30,23 +30,37 @@
 #include <fcntl.h>
 #include <unistd.h>
 #include <sys/mman.h>
+#include <sys/mount.h>
+#include <string.h>
+#include <stdio.h>
 
-#define SYSPROF_FILE "/dev/sysprof-trace"
+typedef struct CPUInfo CPUInfo;
 
+#define N_CPU 8		/* FIXME: Arbitrary number of CPU's */
+		    
 static void set_no_module_error (GError **err);
 static void set_cant_open_error (GError **err, int eno);
 
+struct CPUInfo
+{
+    int			user_pos;
+    int			kernel_pos;
+    SysprofStackTrace	trace;
+};
+
 struct Collector
 {
     CollectorFunc	callback;
     gpointer		data;
     
     StackStash *	stash;
+
+    GString *		input;
     int			fd;
     GTimeVal		latest_reset;
     int			n_samples;
-    SysprofMmapArea *	map_area;
-    unsigned int	current;
+
+    CPUInfo		cpu_info[N_CPU];
 };
 
 /* callback is called whenever a new sample arrives */
@@ -60,6 +74,7 @@ collector_new (CollectorFunc callback,
     collector->data = data;
     collector->fd = -1;
     collector->stash = NULL;
+    collector->input = g_string_new (NULL);
     
     collector_reset (collector);
 
@@ -96,6 +111,7 @@ add_trace_to_stash (const SysprofStackTrace *trace,
     int a;
     gulong addrs_stack[2048];
     int n_alloc;
+    gboolean bad = FALSE;
 
     n_addresses = trace->n_addresses;
     n_kernel_words = trace->n_kernel_words;
@@ -128,10 +144,29 @@ add_trace_to_stash (const SysprofStackTrace *trace,
     {
 	gulong addr = (gulong)trace->addresses[i];
 	
-	process_ensure_map (process, trace->pid, addr);
+	if (!process_ensure_map (process, trace->pid, addr))
+	{
+	    g_print ("user address #%d, %p, was unmapped in %d (%d kernels)\n", i, addr, trace->pid, trace->n_kernel_words);
+	    bad = TRUE;
+	}
+	    
 	addrs[a++] = addr;
     }
 
+    if (bad)
+    {
+	g_print ("bad trace:\n");
+
+	for (i = 0; i < trace->n_addresses; ++i)
+	{
+	    g_print ("    %p\n", trace->addresses[i]);
+	}
+    }
+
+#if 0
+    0xc04068d7
+#endif
+
     /* Add process */
     addrs[a++] = (gulong)process;
 
@@ -165,8 +200,7 @@ in_dead_period (Collector *collector)
     return FALSE;
 }
 
-
-
+#if 0
 static void
 collect_traces (Collector *collector)
 {
@@ -220,18 +254,7 @@ collect_traces (Collector *collector)
     if (collector->callback)
 	collector->callback (first, collector->data);
 }
-
-static void
-on_read (gpointer data)
-{
-    Collector *collector = data;
-    char c;
-    
-    /* Make sure poll() doesn't fire immediately again */
-    read (collector->fd, &c, 1);
-
-    collect_traces (collector);
-}
+#endif
 
 static gboolean
 load_module (void)
@@ -254,62 +277,345 @@ load_module (void)
     return (exit_status == 0);
 }
 
+static void
+warn (const char *text)
+{
+    g_warning ("%s: (%s)\n", text, strerror (errno));
+}
+
+#define SYSPROF_FILE "/sys/kernel/debug/trace_pipe"
+
 static gboolean
-open_fd (Collector *collector,
-	 GError **err)
+write_text (const char *file, const char *text)
 {
-    int fd;
-    void *map_area;
-    
-    fd = open (SYSPROF_FILE, O_RDONLY);
+    int fd = open (file, O_RDWR);
+
     if (fd < 0)
     {
-	if (load_module())
+	g_print ("open %s fail\n",file);
+	warn ("Failed to open");
+	return FALSE;
+    }
+    
+    if (write (fd, text, strlen (text)) < 0)
+    {
+	g_print ("write to %s failed\n", file);
+	warn ("asdf");
+	return FALSE;
+    }
+
+    close (fd);
+    return TRUE;
+}
+
+void
+collector_set_tracing (Collector *collector,
+		       gboolean trace)
+{
+    if (trace)
+	write_text ("/sys/kernel/debug/tracing/tracing_enabled", "1\n");
+    else
+	write_text ("/sys/kernel/debug/tracing/tracing_enabled", "0\n");
+}
+
+#define ENTRY_SIZE  (							\
+	sizeof (guint32) +  /* pid */					\
+	sizeof (guint8) +   /* cpu */					\
+	sizeof (guint64) +  /* timestamp */				\
+	sizeof (gulong) +   /* type */					\
+	sizeof (gulong) +   /* address */				\
+	sizeof (gulong)     /* location */)
+
+#define N_ENTRIES 1024
+
+typedef struct Entry
+{
+    gint pid;
+    gint cpu;
+    guint64 timestamp;
+    glong type;
+    glong address;
+    glong location;
+} Entry;
+
+static char *
+parse_line (char *line, Entry *entry)
+{
+    char *eol;
+    
+    while ((eol = strchr (line, '\n')))
+    {
+#if 0
+	char *l;
+	
+	l = g_strndup (line, eol + 1 - line);
+	g_print ("line: %s", l);
+	g_free (l);
+#endif
+	if (6 == sscanf (line, "%d %d %llu # %ld %ld %ld",
+			 &(entry->pid),
+			 &(entry->cpu),
+			 &(entry->timestamp),
+			 &(entry->type),
+			 &(entry->address),
+			 &(entry->location)))
 	{
-	    GTimer *timer = g_timer_new ();
-	    
-	    while (fd < 0 && g_timer_elapsed (timer, NULL) < 0.5)
-	    {
-		/* Wait for udev to discover the new device.
-		 */
-		usleep (100000);
-		
-		errno = 0;
-		fd = open (SYSPROF_FILE, O_RDONLY);
-	    }
-	    
-	    g_timer_destroy (timer);
+#if 0
+	    g_print ("line: %s", line);
+	    g_print ("Entry:\n");
+	    g_print ("- pid: %d\n", entry->pid);
+	    g_print ("- cpu: %d\n", entry->cpu);
+	    g_print ("- timestamp: %lld\n", entry->timestamp);
+	    g_print ("- type: %ld\n", entry->type);
+	    g_print ("- address: %ld\n", entry->address);
+	    g_print ("- location: %ld\n", entry->location);
+#endif
 	    
-	    if (fd < 0)
-	    {
-		set_cant_open_error (err, errno);
-		return FALSE;
-	    }
+	    return eol + 1;
 	}
+#if 0
+	else
+	    g_print ("unparsable\n");
+#endif
+
+	line = eol + 1;
+    }
+
+    return NULL;
+}
+
+static CPUInfo *
+find_cpu_info (Collector *collector, int pid)
+{
+    int i;
+    
+    /* New stack trace - find a CPUInfo that is not in use */
+    for (i = 0; i < N_CPU; ++i)
+    {
+	if (collector->cpu_info[i].trace.pid == pid)
+	    return &(collector->cpu_info[i]);
+    }
+    
+    return NULL;
+}
+
+static gboolean
+process_entry (Collector *collector, Entry *entry)
+{
+    CPUInfo *info = NULL;
 	
-	if (fd < 0)
+    /* There can be up to N_CPU stacktraces in progress at the same
+     * time, but processes can move between CPU's in the middle of
+     * the stack-tracing, so we can't have CPU specific states.
+     *
+     * I am assuming here that we can't have more than one stacktrace
+     * in progress per PID
+     */
+    if (entry->type == 0)
+    {
+	/* Beginning of stack trace */
+	if ((info = find_cpu_info (collector, -1)))
+	{
+	    info->trace.pid = entry->pid;
+	    info->trace.truncated = FALSE;
+	    info->user_pos = 0;
+	    info->kernel_pos = 0;
+	}
+    }
+    else if (entry->type == 1)
+    {
+	/* Kernel address */
+	if ((info = find_cpu_info (collector, entry->pid)))
+	{
+	    if (info->kernel_pos < SYSPROF_MAX_ADDRESSES)
+		info->trace.kernel_stack[info->kernel_pos++] = (void *)entry->address;
+	    else
+		info->trace.truncated = TRUE;
+	}
+    }
+    else if (entry->type == 2)
+    {
+	/* User address */
+	if ((info = find_cpu_info (collector, entry->pid)))
+	{
+	    if (info->user_pos < SYSPROF_MAX_ADDRESSES)
+		info->trace.addresses[info->user_pos++] = (void *)entry->address;
+	    else
+		info->trace.truncated = TRUE;	    
+	}
+    }
+    else if (entry->type == 3)
+    {
+	/* End of stack trace */
+	if ((info = find_cpu_info (collector, entry->pid)))
 	{
-	    set_no_module_error (err);
+	    info->trace.n_kernel_words = info->kernel_pos;
+	    info->trace.n_addresses = info->user_pos;
+
+#if 0
+	    if (info->kernel_pos == 1)
+		g_print ("only one kernel address: user words: %d\n", info->user_pos);
+#endif
 	    
-	    return FALSE;
+	    add_trace_to_stash (&(info->trace), collector->stash);
+	
+	    collector->n_samples++;
+
+	    info->trace.pid = -1;
 	}
     }
+}
+
+static void
+parse_input (Collector *collector)
+{
+    Entry entry;
+    char *str, *s;
+    int len;
+    /* Four states */
+    gboolean ignoring;
+    SysprofStackTrace trace;
+    int pos;
+    gboolean update = FALSE;
+    
+    str = collector->input->str;
+
+    while ((s = parse_line (str, &entry)))
+    {
+	process_entry (collector, &entry);
+
+	str = s;
+    }
+
+    g_string_erase (collector->input, 0, str - collector->input->str);
+}
+
+/* */
+static void
+on_read (gpointer data)
+{
+    Collector *collector = data;
+    char input [N_ENTRIES * ENTRY_SIZE];
+    int n_bytes;
+    gboolean first;
+    int i;
+    static int n_reads;
+
+    memset (input, '1', sizeof input);
     
-    map_area = mmap (NULL, sizeof (SysprofMmapArea),
-		     PROT_READ, MAP_SHARED, fd, 0);
+    n_bytes = read (collector->fd, input, sizeof (input));
+
+    g_assert (data == collector);
     
-    if (map_area == MAP_FAILED)
+    if (n_bytes <= 0)
+    {
+	g_print ("result: %d\n", n_bytes);
+	return;
+    }
+
+    n_reads++;
+    if (n_reads % 10000 == 0)
+	g_print ("%d reads\n", n_reads);
+    
+    if (in_dead_period (collector))
+	return;
+    
+    first = collector->n_samples == 0;
+
+    /* Sometimes we get nul bytes in the input. This is inconvenient, so
+     * replace them with newlines.
+     */
+    for (i = 0; i < n_bytes; ++i)
+    {
+	if (input[i] == 0)
+	    input[i] = '\n';
+    }
+    
+    g_string_append_len (collector->input, input, n_bytes);
+
+    parse_input (collector);
+    
+    if (collector->callback && collector->n_samples > 0)
+	collector->callback (first, collector->data);
+}
+
+static gboolean
+start_tracing (Collector *collector,
+	       GError **err)
+{
+    int fd;
+    int i;
+    
+    if (access ("/sys/kernel/debug/tracing", X_OK) < 0)
+    {
+	mount ("nodev", "/sys/kernel/debug", "debugfs", 0, NULL);
+
+	if (access ("/sys/kernel/debug/tracing", X_OK) < 0)
+	{
+	    g_print ("couldn't mount directory FIXME error\n");
+	    return FALSE;
+	}
+    }
+
+    if (!write_text ("/sys/kernel/debug/tracing/iter_ctrl", "noblock"))
+    {
+	return FALSE;
+    }
+    
+    if (!write_text ("/sys/kernel/debug/tracing/current_tracer", "sysprof\n"))
+    {
+	warn ("Failed to append sysprof\n");
+	return FALSE;
+    }
+
+    if (!write_text ("/sys/kernel/debug/tracing/tracing_enabled", "0\n"))
     {
-	close (fd);
-	set_cant_open_error (err, errno);
 	
+    }
+    
+    if (!write_text ("/sys/kernel/debug/tracing/iter_ctrl", "raw\n"))
+    {
+	g_print ("Failed to make raw\n");
+	return FALSE;
+    }
+
+    if (!write_text ("/sys/kernel/debug/tracing/iter_ctrl", "nobin\n"))
+    {
+	g_print ("Failed to make binary\n");
+	return FALSE;
+    }
+
+#if 0
+    if (!write_text ("/sys/kernel/debug/tracing/sysprof_sample_period", "10000\n"))
+    {
+	g_print ("Failed to set sample period\n");
+	return FALSE;
+    }
+#endif
+
+    fd = open ("/sys/kernel/debug/tracing/trace_pipe", O_RDONLY);
+    if (fd < 0)
+    {
+	g_print ("Failed to open trace pipe\n");
+	return FALSE;
+    }
+
+    g_print ("fd: %d\n", fd);
+    
+    if (!write_text ("/sys/kernel/debug/tracing/tracing_enabled", "1\n"))
+    {
+	g_print ("Failed to enable\n");
 	return FALSE;
     }
+    else
+	g_print ("enabled\n");
+
+    fd_add_watch (fd, collector);
     
-    collector->map_area = map_area;
-    collector->current = 0;
     collector->fd = fd;
-    fd_add_watch (collector->fd, collector);
+
+    for (i = 0; i < N_CPU; ++i)
+	collector->cpu_info[i].trace.pid = -1;
     
     return TRUE;
 }
@@ -318,7 +624,9 @@ gboolean
 collector_start (Collector  *collector,
 		 GError    **err)
 {
-    if (collector->fd < 0 && !open_fd (collector, err))
+    g_print ("start\n");
+    
+    if (collector->fd < 0 && !start_tracing (collector, err))
 	return FALSE;
     
     /* Hack to make sure we parse the kernel symbols before
@@ -338,11 +646,11 @@ collector_stop (Collector *collector)
     {
 	fd_remove_watch (collector->fd);
 	
-	munmap (collector->map_area, sizeof (SysprofMmapArea));
-	collector->map_area = NULL;
-	collector->current = 0;
-	
 	close (collector->fd);
+    
+	if (!write_text ("/sys/kernel/debug/tracing/tracing_enabled", "0\n"))
+	    g_print ("Failed to disable\n");
+	
 	collector->fd = -1;
     }
 }
@@ -354,7 +662,7 @@ collector_reset (Collector *collector)
 	stack_stash_unref (collector->stash);
     
     process_flush_caches();
-    
+
     collector->stash = stack_stash_new (NULL);
     collector->n_samples = 0;
     
@@ -364,6 +672,9 @@ collector_reset (Collector *collector)
 int
 collector_get_n_samples (Collector *collector)
 {
+#if 0
+    g_print ("returning %d samples\n", collector->n_samples);
+#endif
     return collector->n_samples;
 }
 
diff --git a/collector.h b/collector.h
index 3f9420d..11131db 100644
--- a/collector.h
+++ b/collector.h
@@ -39,6 +39,8 @@ Collector *collector_new            (CollectorFunc   callback,
 gboolean   collector_start          (Collector      *collector,
 				     GError        **err);
 void       collector_stop           (Collector      *collector);
+void	   collector_set_tracing    (Collector *collector,
+				     gboolean trace);
 void       collector_reset          (Collector      *collector);
 int        collector_get_n_samples  (Collector      *collector);
 Profile *  collector_create_profile (Collector      *collector);
diff --git a/configure.ac b/configure.ac
index aef46d4..671abfe 100644
--- a/configure.ac
+++ b/configure.ac
@@ -1,6 +1,6 @@
 AC_PREREQ(2.54)
 
-AC_INIT([sysprof], [1.1.0])
+AC_INIT([sysprof], [1.1.0.2-ftrace])
 AC_CONFIG_SRCDIR(sysprof.glade)
 
 AM_INIT_AUTOMAKE(no-define)
@@ -47,7 +47,7 @@ AC_DEFINE_DIR(DEBUGDIR, debugdir,
 AC_ARG_ENABLE(kernel-module,
      AC_HELP_STRING(--disable-kernel-module, disable building kernel module))
 
-kernel_module="yes"
+kernel_module="no"
 if test "x$enableval" = "xno"; then
 	kernel_module="no"
 fi
diff --git a/process.c b/process.c
index 45b45d9..d62cdb1 100644
--- a/process.c
+++ b/process.c
@@ -311,18 +311,20 @@ page_size (void)
     return page_size;
 }
 
-void
+gboolean
 process_ensure_map (Process *process, int pid, gulong addr)
 {
+    gulong orig = addr;
+    
     /* Round down to closest page */
     
     addr = (addr - addr % page_size());
     
     if (process_has_page (process, addr))
-	return;
+	return TRUE;
     
     if (g_list_find (process->bad_pages, (gpointer)addr))
-	return;
+	return TRUE;
     
     /* a map containing addr was not found */
     if (process->maps)
@@ -332,11 +334,13 @@ process_ensure_map (Process *process, int pid, gulong addr)
 
     if (!process_has_page (process, addr))
     {
-#if 0
-	g_print ("Bad page: %p\n", addr);
-#endif
+	g_print ("Bad page: %d %p\n", pid, orig);
 	process->bad_pages = g_list_prepend (process->bad_pages, (gpointer)addr);
+
+	return FALSE;
     }
+
+    return TRUE;
 }
 
 static gboolean
diff --git a/process.h b/process.h
index a72714c..833a3e9 100644
--- a/process.h
+++ b/process.h
@@ -48,7 +48,7 @@ typedef struct Process Process;
  */
 
 Process *     process_get_from_pid                (int         pid);
-void          process_ensure_map                  (Process    *process,
+gboolean      process_ensure_map                  (Process    *process,
 						   int         pid,
 						   gulong      address);
 const char *  process_lookup_symbol		  (Process    *process,
diff --git a/sysprof.c b/sysprof.c
index 68e0fe6..6778d23 100644
--- a/sysprof.c
+++ b/sysprof.c
@@ -118,6 +118,12 @@ show_samples (Application *app)
 {
     char *label;
     int n_samples;
+    gboolean profiling = app->state == PROFILING;
+
+#if 0
+    if (profiling)
+	collector_set_tracing (app->collector, FALSE);
+#endif
     
     switch (app->state)
     {
@@ -153,6 +159,16 @@ show_samples_timeout (gpointer data)
     show_samples (app);
     
     app->timeout_id = 0;
+
+#if 0
+    gdk_window_process_all_updates ();
+    gdk_flush ();
+#endif
+    
+#if 0
+    if (profiling)
+	collector_set_tracing (app->collector, TRUE);
+#endif
     
     return FALSE;
 }