Re: Profiling sleep times?

["avagin@gmail.com" <avagin@gmail.com>]

[-- Attachment #1: Type: text/plain, Size: 416 bytes --]

> Andrew, are you already working on user space patches?

Yes, I'm working. I've attached the draft version.

The example of usage:
#./perf record -ag -e sched:sched_switch --filter "prev_state == 1" -e 
sched:sched_process_exit -e sched:sched_stat_sleep --filter "comm == 
foo" ~/foo

#./perf inject -s -i perf.data -o perf.data.d

#./perf report -i perf.data.d

I will be glad to receive any comments.

>
> -Arun


[-- Attachment #2: 0001-perf-teach-perf-inject-to-work-with-files.patch --]
[-- Type: text/plain, Size: 2745 bytes --]

From c2cd0d73c11687fbc67884aba337f497e13890f9 Mon Sep 17 00:00:00 2001
From: Andrew Vagin <avagin@openvz.org>
Date: Tue, 4 Oct 2011 16:10:23 +0400
Subject: [PATCH 1/3] perf: teach "perf inject" to work with files

Before this patch "perf inject" can only handle data from pipe.

I want to use "perf inject" for reworking events. Look at my following patch.

Signed-off-by: Andrew Vagin <avagin@openvz.org>
---
 tools/perf/builtin-inject.c |   33 +++++++++++++++++++++++++++++++--
 1 files changed, 31 insertions(+), 2 deletions(-)

diff --git a/tools/perf/builtin-inject.c b/tools/perf/builtin-inject.c
index 8dfc12b..8df8b71 100644
--- a/tools/perf/builtin-inject.c
+++ b/tools/perf/builtin-inject.c
@@ -13,7 +13,12 @@
 
 #include "util/parse-options.h"
 
-static char		const *input_name = "-";
+static char		const *input_name	= "-";
+static const char	*output_name		= "-";
+static int		pipe_output		= 0;
+static int		output;
+static u64		bytes_written		= 0;
+
 static bool		inject_build_ids;
 
 static int perf_event__repipe_synth(union perf_event *event,
@@ -25,12 +30,14 @@ static int perf_event__repipe_synth(union perf_event *event,
 	size = event->header.size;
 
 	while (size) {
-		int ret = write(STDOUT_FILENO, buf, size);
+		int ret = write(output, buf, size);
 		if (ret < 0)
 			return -errno;
 
 		size -= ret;
 		buf += ret;
+
+		bytes_written += ret;
 	}
 
 	return 0;
@@ -213,8 +220,14 @@ static int __cmd_inject(void)
 	if (session == NULL)
 		return -ENOMEM;
 
+	if (!pipe_output)
+		lseek(output, session->header.data_offset, SEEK_SET);
 	ret = perf_session__process_events(session, &inject_ops);
 
+	if (!pipe_output) {
+		session->header.data_size += bytes_written;
+		perf_session__write_header(session, session->evlist, output, true);
+	}
 	perf_session__delete(session);
 
 	return ret;
@@ -228,6 +241,10 @@ static const char * const report_usage[] = {
 static const struct option options[] = {
 	OPT_BOOLEAN('b', "build-ids", &inject_build_ids,
 		    "Inject build-ids into the output stream"),
+	OPT_STRING('i', "input", &input_name, "file",
+		    "input file name"),
+	OPT_STRING('o', "output", &output_name, "file",
+		    "output file name"),
 	OPT_INCR('v', "verbose", &verbose,
 		 "be more verbose (show build ids, etc)"),
 	OPT_END()
@@ -243,6 +260,18 @@ int cmd_inject(int argc, const char **argv, const char *prefix __used)
 	if (argc)
 		usage_with_options(report_usage, options);
 
+	if (!strcmp(output_name, "-")) {
+		pipe_output = 1;
+		output = STDOUT_FILENO;
+	} else {
+		output = open(output_name, O_CREAT| O_WRONLY | O_TRUNC,
+							S_IRUSR | S_IWUSR);
+		if (output < 0) {
+			perror("failed to create output file");
+			exit(-1);
+		}
+	}
+
 	if (symbol__init() < 0)
 		return -1;
 
-- 
1.7.1


[-- Attachment #3: 0003-perf-add-scripts-for-collecting-D-state-statistics.patch --]
[-- Type: text/plain, Size: 1420 bytes --]

From e08809ba075d92e60f669fc62c48128e06c834fb Mon Sep 17 00:00:00 2001
From: Andrew Vagin <avagin@openvz.org>
Date: Thu, 6 Oct 2011 12:18:44 +0400
Subject: [PATCH 3/3] perf: add scripts for collecting D-state statistics


Signed-off-by: Andrew Vagin <avagin@openvz.org>
---
 .../perf/scripts/python/bin/task-in-d-state-record |    2 ++
 .../perf/scripts/python/bin/task-in-d-state-report |    6 ++++++
 2 files changed, 8 insertions(+), 0 deletions(-)
 create mode 100644 tools/perf/scripts/python/bin/task-in-d-state-record
 create mode 100644 tools/perf/scripts/python/bin/task-in-d-state-report

diff --git a/tools/perf/scripts/python/bin/task-in-d-state-record b/tools/perf/scripts/python/bin/task-in-d-state-record
new file mode 100644
index 0000000..d70bed0
--- /dev/null
+++ b/tools/perf/scripts/python/bin/task-in-d-state-record
@@ -0,0 +1,2 @@
+#!/bin/bash
+perf record -ag -e sched:sched_switch --filter "prev_state == 2" -e sched:sched_stat_iowait -e sched:sched_process_exit $@
diff --git a/tools/perf/scripts/python/bin/task-in-d-state-report b/tools/perf/scripts/python/bin/task-in-d-state-report
new file mode 100644
index 0000000..f1ab71e
--- /dev/null
+++ b/tools/perf/scripts/python/bin/task-in-d-state-report
@@ -0,0 +1,6 @@
+#!/bin/bash
+# description: D-state statistics
+# args:
+perf inject -s -i perf.data -o perf.data.d || exit
+perf report -i perf.data.d || exit
+unlink perf.data.d
-- 
1.7.1


[-- Attachment #4: 0002-perf-teach-perf-inject-to-merge-sched_stat_-and-sche.patch --]
[-- Type: text/plain, Size: 4355 bytes --]

From 7a3152c03d07d30f47ab4fe9295212330bf821e4 Mon Sep 17 00:00:00 2001
From: Andrew Vagin <avagin@openvz.org>
Date: Tue, 4 Oct 2011 16:54:15 +0400
Subject: [PATCH 2/3] perf: teach perf inject to merge sched_stat_* and sched_switch events

You may want to know where and how long a task is sleeping. A callchain
may be found in sched_switch and a time slice in stat_iowait, so I add
handler in perf inject for merging this events.

My code saves sched_switch event for each process and when it meets
stat_iowait, it reports the sched_switch event, because it contains a
correct callchain. By another words it replaces all stat_iowait events
on proper sched_switch events.

My code doesn't change events.

Signed-off-by: Andrew Vagin <avagin@openvz.org>
---
 tools/perf/builtin-inject.c |   87 +++++++++++++++++++++++++++++++++++++++++++
 1 files changed, 87 insertions(+), 0 deletions(-)

diff --git a/tools/perf/builtin-inject.c b/tools/perf/builtin-inject.c
index 8df8b71..10bdd65 100644
--- a/tools/perf/builtin-inject.c
+++ b/tools/perf/builtin-inject.c
@@ -12,6 +12,8 @@
 #include "util/debug.h"
 
 #include "util/parse-options.h"
+#include "util/trace-event.h"
+
 
 static char		const *input_name	= "-";
 static const char	*output_name		= "-";
@@ -20,6 +22,7 @@ static int		output;
 static u64		bytes_written		= 0;
 
 static bool		inject_build_ids;
+static bool		inject_sched_stat;
 
 static int perf_event__repipe_synth(union perf_event *event,
 				    struct perf_session *session __used)
@@ -179,6 +182,85 @@ repipe:
 	return 0;
 }
 
+struct event_entry
+{
+	struct list_head list;
+	u32 pid;
+	struct perf_event_header header;
+};
+
+#define ENT_SIZE(size) ((size) + offsetof(event_entry, header))
+
+static LIST_HEAD(samples);
+
+static int perf_event__sched_stat(union perf_event *event,
+				      struct perf_sample *sample,
+				      struct perf_evsel *evsel __used,
+				      struct perf_session *session)
+{
+	int type;
+	struct event *e;
+	const char *evname = NULL;
+	uint32_t size;
+	void *buf = event;
+	struct event_entry *ent;
+	union perf_event *event_sw = NULL;
+	struct perf_sample sample_sw;
+	int sched_process_exit;
+
+	size = event->header.size;
+
+	type = trace_parse_common_type(sample->raw_data);
+	e = trace_find_event(type);
+	if (e)
+		evname = e->name;
+
+	sched_process_exit = !strcmp(evname, "sched_process_exit");
+
+	if (!strcmp(evname, "sched_switch") ||  sched_process_exit) {
+		list_for_each_entry(ent, &samples, list)
+			if (sample->pid == ent->pid)
+				break;
+
+		if (&ent->list != &samples) {
+			list_del(&ent->list);
+			free(ent);
+		}
+
+		if (sched_process_exit)
+			return 0;
+
+		ent = malloc(size + offsetof(struct event_entry, header));
+		ent->pid = sample->pid;
+		memcpy(&ent->header, buf, size);
+		list_add(&ent->list, &samples);
+		return 0;
+
+	} else if (!strncmp(evname, "sched_stat_", 11)) {
+		u32 pid;
+
+		pid = raw_field_value(e, "pid", sample->raw_data);
+
+		list_for_each_entry(ent, &samples, list) {
+			if (pid == ent->pid)
+				break;
+		}
+
+		if (&ent->list == &samples) {
+			pr_warning("Could not find sched_switch for pid %u\n", pid);
+			return 0;
+		}
+
+		event_sw = (union perf_event *) &ent->header;
+		perf_session__parse_sample(session, event_sw, &sample_sw);
+		perf_event__repipe(event_sw, &sample_sw, session);
+		return 0;
+	}
+
+	perf_event__repipe(event, sample, session);
+
+	return 0;
+}
 struct perf_event_ops inject_ops = {
 	.sample		= perf_event__repipe_sample,
 	.mmap		= perf_event__repipe,
@@ -214,6 +296,9 @@ static int __cmd_inject(void)
 		inject_ops.mmap		= perf_event__repipe_mmap;
 		inject_ops.fork		= perf_event__repipe_task;
 		inject_ops.tracing_data	= perf_event__repipe_tracing_data;
+	} else if (inject_sched_stat) {
+		inject_ops.sample	= perf_event__sched_stat;
+		inject_ops.ordered_samples		= true;
 	}
 
 	session = perf_session__new(input_name, O_RDONLY, false, true, &inject_ops);
@@ -241,6 +326,8 @@ static const char * const report_usage[] = {
 static const struct option options[] = {
 	OPT_BOOLEAN('b', "build-ids", &inject_build_ids,
 		    "Inject build-ids into the output stream"),
+	OPT_BOOLEAN('s', "sched-stat", &inject_sched_stat,
+		    "correct call-chains for shed-stat-*"),
 	OPT_STRING('i', "input", &input_name, "file",
 		    "input file name"),
 	OPT_STRING('o', "output", &output_name, "file",
-- 
1.7.1