draft chaintime-nd.stp

gistfile1.txt

#!/usr/bin/stap
/*
 * chaintime-nd.stp	Measure off-CPU time by stack trace & wakeup stack.
 *			For Linux, uses SystemTap (non-debuginfo).
 *
 * USAGE: ./chaintime-nd.stp [duration]
 *
 * This script uses the kernel tracepoint sched:sched_switch to measure off-CPU
 * time along with the blocked stack trace, and sched:sched_wakeup to measure
 * the wakeup stack for sleeping threads, to associate with the blocked stack.
 * These are typically high overhead tracepoints, so test and understand
 * overhead before use.
 *
 * From systemtap-lwtools: https://github.com/brendangregg/systemtap-lwtools
 *
 * See the corresponding man page (in systemtap-lwtools) for more info.
 *
 * Copyright (C) 2015 Brendan Gregg.
 *
 * This program is free software; you can redistribute it and/or modify
 * it under the terms of the GNU General Public License as published by
 * the Free Software Foundation; either version 2 of the License, or
 * (at your option) any later version.
 *
 * This program is distributed in the hope that it will be useful,
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 * GNU General Public License for more details.
 *
 * 02-Apr-2015	Brendan Gregg	Created this.
 */

global ts[65536];	# 65536 is max concurrent I/O
global lat, wokeby;
global secs = 0, duration = 0, output = 0;

probe begin
{
	printf("Tracing off-CPU time with wakeups and stacks... ");
	if (argv_1 != "") {
		duration = strtol(argv_1, 10);
		printf("Tracing for %d seconds.\n", duration);
	} else {
		printf("Hit Ctrl-C to end.\n");
	}
}

/* kernel.trace("sched:sched_switch") $prev:struct task_struct* $next:struct task_struct* */
probe kernel.trace("sched:sched_switch")
{
	now = gettimeofday_us();
	ts[$prev->pid] = now;
	if (ts[$next->pid]) {
		pidcomm = sprintf("%s-%d", kernel_string($next->comm),
		    $next->pid);
		lat[wokeby[$next->pid], backtrace(), pidcomm] <<<
		    now - ts[$next->pid];
		ts[$next->pid] = 0;
	}

	delete wokeby[$prev->pid];
}

/* kernel.trace("sched:sched_wakeup") $p:struct task_struct* $success:int */
probe kernel.trace("sched:sched_wakeup")
{
	if ($success && ts[$p->pid]) {
		wokeby[$p->pid] = backtrace();
	}
}


function print_report()
{
	printf("\noff-CPU time (ns):\n\n");
	/* kws0: kernel wakeup stack 0; kss: kernel sleep stack */
	foreach ([kws0, kss, commpid] in lat+) {

	/* for testing, only match "sleep" commands: */
		print_stack(kws0);
		printf("woke-up-by\n");
		print_stack(kss);
		printf("%s\n", commpid);
		printf("%d\n\n", @sum(lat[kws0, kss, commpid]));
	}
	delete lat;
}

probe timer.s(1)
{
	if (duration && ++secs == duration) {
		print_report();
		exit();
	}
}

probe end
{
	!duration && print_report();
	delete secs;
	delete output;
}