www.pudn.com > Linux2410_kernel.rar > imaxoff.c


/*
 * FILE NAME imaxoff.c
 *
 * BRIEF MODULE DESCRIPTION
 * This file implements the tracking of the places where interrupts
 * are turned off.
 *
 * Author: David Singleton 
 *	MontaVista Software, Inc.
 *      support@mvista.com
 *
 * Copyright 2001 MontaVista Software Inc.
 *
 *  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  SOFTWARE  IS PROVIDED   ``AS  IS'' AND   ANY  EXPRESS OR IMPLIED
 *  WARRANTIES,   INCLUDING, BUT NOT  LIMITED  TO, THE IMPLIED WARRANTIES OF
 *  MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED.  IN
 *  NO  EVENT  SHALL   THE AUTHOR  BE    LIABLE FOR ANY   DIRECT, INDIRECT,
 *  INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT
 *  NOT LIMITED   TO, PROCUREMENT OF  SUBSTITUTE GOODS  OR SERVICES; LOSS OF
 *  USE, DATA,  OR PROFITS; OR  BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON
 *  ANY THEORY OF LIABILITY, WHETHER IN  CONTRACT, STRICT LIABILITY, OR TORT
 *  (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF
 *  THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
 *
 *  You should have received a copy of the  GNU General Public License along
 *  with this program; if not, write  to the Free Software Foundation, Inc.,
 *  675 Mass Ave, Cambridge, MA 02139, USA.
 */
#include 
#include 
#include 
#include 
#include 
#include 

unsigned ticks_per_usec;
static const char *cli_file;
static unsigned cli_line_no;
static unsigned cli_ticks;
static int latency_debug = 0;
interrupt_latency_log_t latency = {
	0,
	"worst case interrupt hold off",
	0,
	0,
	0,

	1,
	0xffffffff,

	0,
	0,

	0,
	0,
	0,
	0,
	0,
	0,
	0
};

/*
 * on PPC and MIPs we branch-link here from ret_from_exception to
 * catch interrupts coming back on.  We also just log the fact that
 * interrupts are coming back on, we don't actually turn them on, thus
 * the third parameter, just_logging. 
 */

void __noinstrument
intr_ret_from_exception()
{
	intr_sti(__BASE_FILE__, __LINE__, 1);
}

/* 
 * If this is the outer most cli we log it.  If it's a nested cli, 
 * that is trying to turn interupts off and they are already off
 * we don't note the time or call to cli.
 * To keep our accounting straight, we set latency.sync to 1 in
 * this routine and to zero in intr_sti().  This helps us keep
 * track that we have noted the cli for this sti.  We want to
 * keep cli()/sti() pairs matched.  If you have any doubt, read the code
 * at the file and line numbers reported in /proc/imaxoff.  If they
 * are the right cli/sti pairs then there is yet another hole in
 * the instrumentation where the kernel is turning interrupts on
 * and off and we've missed it.
 */

void __noinstrument intr_cli(const char *cli_fname, unsigned cli_lineno)
{
	unsigned flag;

	__save_flags(flag); 
	__intr_cli();

	/* if we are not logging or we have an error, do nothing */
	if (latency.logging == OFF) {
		return;
	}
	
	/* 
 	 * If interrupts were already disabled then we don't
 	 * need to log it . . this is a nested interrupt. We
	 * want the outer pair of cli/sti.
	 */

	if (!INTERRUPTS_ENABLED(flag)) {
		latency.skip_cli++;
		return;
	}

	/* debug */
	if (latency.sync == 1) {
		latency.cli_error++;
	}
	latency.sync = 1;

	latency.iret_count = 0;

	/* Read the Time Stamp Counter */
	cli_file = cli_fname;
	cli_line_no = cli_lineno;
	readclock(cli_ticks);

	return;
}

/*
 * We want to make sure we have the sti that corresponds to the cli
 * caught above.  To do this we make sure the sync count is 1, as set
 * by intr_cli().  Originally iret_count was meant to catch returns
 * to userland.  If we'd caught an sti() in the kernel and somehow
 * we went back to userland before this sti() was called the cli/sti
 * pair is bogus.  I don't think iret_count ever worked.  I've kept it
 * for historical reasons and perhaps someday I can make it work.
 * The just_logging parameter is for those situations where we know
 * we are going to be turning interrupts back on in return from
 * exception. We grab the information for logging only but don't 
 * do the __sti we let the original code path do it.  An example is the
 * do_IRQ path for ARM.  We know the exception handler will turn it
 * back on, but it's such a nest of handlers that it's easier to just
 * log it in do_IRQ and leave the exception handlers alone.  We do
 * instrument the exception handlers for PPC and MIPs, they have simple
 * branch-link instructions so we can make the call just before
 * interrupts are turned back on.
 */

#define MAXINT	0x7fffffff

void __noinstrument intr_sti(const char *fname, unsigned lineno,
			     int just_logging)
{
	unsigned long flag;
	unsigned long sti_ticks = 0;
	unsigned usecs;
	unsigned long old_lowest;
	int i, index;

	__save_flags(flag);

	/* 
	 * logging is turned off in the boot path until we have registered
	 * with /proc.
	 */

	if (latency.logging == OFF) {
		goto out;
	}

	/* 
	 * If interrupts are already on we don't have to log this call.
	 */

	if (INTERRUPTS_ENABLED(flag)) {
		latency.skip_sti++;
		goto out;
	}

	/*
	 * Sync gets set to 1 by intr_cli.  If it's not one then we don't
	 * have the right cli/sti pair.
	 */

	if (latency.sync != 1) {
		latency.sti_error++;
		goto out;
	}

	/*
	 * If iret_count is not zero we've gone to user land and this is
	 * not a valid cli/sti pair.  I pointed out that no one sets this,
	 * but the originator had no comment . . 
	 */

	if (latency.iret_count != 0) {
		latency.sti_break_error++;
		goto out;
	}

	readclock(sti_ticks);
	latency.sync = 0;

	/*
	 * reading the clock is platform dependent and clock_to_usecs
	 * is setup by each platform as well usually in asm/preem_latency.h.  
	 * get the time and log all the time for this cli/sti pair.
	 */

	usecs = clock_to_usecs(clock_diff(cli_ticks, sti_ticks));
	inthoff_logentry(usecs);
	latency.total_ints++;

	/*
	 * find the lowest hold off time and substitute the lowest with 
	 * the new entry, iff the new entry is lower.
	 * We don't keep multiple entries for the same offending
	 * file and line pair.  Only one entry for printk, for example.
	 * But we want the highest hold off time shown for all
	 * occurances of printk . . . 
	 */

	old_lowest = MAXINT;
	for (index = i = 0; i < NUM_LOG_ENTRIES; i++) {
		if (old_lowest > latency.log[i].interrupts_off) {
			old_lowest = latency.log[i].interrupts_off;
			index = i;	
		}
		if ((lineno == latency.log[i].sti_line) &&
		    (cli_line_no == latency.log[i].cli_line) &&
		    (fname[0] == latency.log[i].sti_file[0]) &&      
		    (cli_file[0] == latency.log[i].cli_file[0])) {    

			if (usecs > latency.log[i].interrupts_off)
				latency.log[i].interrupts_off = usecs;
			latency.log[i].multiples++;
			goto out;
		}
	}
	if ((usecs < old_lowest) && (old_lowest != MAXINT)) {
		goto out;
	}

	latency.log[index].interrupts_off = usecs;
	latency.log[index].sti_file = fname;
	latency.log[index].sti_line = lineno;
	latency.log[index].sti_ticks = sti_ticks;
	latency.log[index].cli_file = cli_file;
	latency.log[index].cli_line = cli_line_no;
	latency.log[index].cli_ticks = cli_ticks;
	latency.log[index].multiples++;

	/*
	 * We have a couple of places where we instrument
	 * the code to inform us that interrupt are coming
	 * back on, without actually turning them one,
	 * like in arm/kernel/irq.c.  We just log it and
	 * let the original code turn the interrupts back on.
	 */
out:
	if (!just_logging)
		__intr_sti();
}

void __noinstrument intr_restore_flags(const char *fname,
				       unsigned lineno, unsigned x)
{
	unsigned long flag;

	__save_flags(flag);

	if (latency.logging == OFF) {
		__intr_restore_flags(x);
		return;
	}

	if (!INTERRUPTS_ENABLED(flag) && INTERRUPTS_ENABLED(x)) {
		latency.restore_sti++;
		intr_sti(fname, lineno, 0);
	}

	if (INTERRUPTS_ENABLED(flag) && !INTERRUPTS_ENABLED(x)) {
		latency.restore_cli++;
		intr_cli(fname, lineno);
	}

	__intr_restore_flags(x);
}

static ssize_t __noinstrument
imaxoff_write_proc(struct file * file, const char * buf, size_t count,
		   loff_t *ppos)
{
	extern unsigned long total_ilat_samples;
	extern unsigned long bucketlog[BUCKETS];

        total_ilat_samples = 0;
	memset(&bucketlog, 0, sizeof(unsigned long) * BUCKETS);
	memset(&latency, 0, sizeof(interrupt_latency_log_t));
	latency.logging = ON;
	return count;
}   

static int g_read_completed = 0;

static int __noinstrument imaxoff_read_proc(
	char *page_buffer,
	char **my_first_byte,
	off_t virtual_start,
	int length,
	int *eof,
	void *data)
{
	int my_buffer_offset = 0;
	char * const my_base = page_buffer;
	int i;
	if (virtual_start == 0) {
		/* 
		 * Just been opened so display the header information 
		 * also stop logging  BUGBUG: stop logging while we are 
		 * reading, initialize the index numbers in the log array
		 */
		g_read_completed = 0;
		my_buffer_offset += sprintf(my_base + my_buffer_offset,
		   "Maximum Interrupt Hold Off Times and Callers\n");

	} else if (g_read_completed == (NUM_LOG_ENTRIES + latency_debug)) {
		 *eof = 1;
		 return 0;
	}

	if (latency_debug) {
		my_buffer_offset += sprintf(my_base + my_buffer_offset,
		     "iret_count %u sync %u skip_sti %u skip_cli %u\n"
		     "sti_error %u cli_error %u sti_break_error %u "
		     "restore_sti %u restore_cli %u\n",
		     latency.iret_count, latency.sync, latency.skip_sti,
		     latency.skip_cli, latency.sti_error, latency.cli_error,
		     latency.sti_break_error, latency.restore_sti,
		     latency.restore_cli);
		g_read_completed++;
	}
	for (i = 0; i < NUM_LOG_ENTRIES; i++) {
		my_buffer_offset += sprintf(my_base + my_buffer_offset,
		    "%d) %u us interrupts off\n\tcli call in file %s"
		    " (%d times)\n"
		    "\tcli call at line %5u\t\n\tsti call in file %s\n"
		    "\tsti call at line %5u\n"
		    "\tcli timer count %10u\n\tsti timer count %10u\n", 
		    i, latency.log[i].interrupts_off,
		    latency.log[i].cli_file, latency.log[i].multiples,
		    latency.log[i].cli_line, latency.log[i].sti_file, 
		    latency.log[i].sti_line, latency.log[i].cli_ticks, 
		    latency.log[i].sti_ticks);
		g_read_completed++;
	}

	*my_first_byte = page_buffer;
	return  my_buffer_offset;
}

int __noinstrument __init
holdoffs_init(void)
{
        struct proc_dir_entry *entry;

#ifdef CONFIG_SMP
	printk("Interrupt holdoff times are not supported on SMP systems.\n");
	latency.logging = OFF;
#else
#ifdef CONFIG_PROC_FS
	entry = create_proc_read_entry("imaxoff", 0, 0, imaxoff_read_proc, 0);
	if (entry)
		entry->write_proc = (write_proc_t *)imaxoff_write_proc;
#endif /* CONFIG_PROC_FS */
	readclock_init();
	if (ticks_per_usec) {
		printk("Interrupt holdoff maximums being captured.\n");
		latency.logging = ON;
	} else {
		printk("Interrupt Latency timer is NOT on! No data will be collected\n");
	}
#endif /* ! CONFIG_SMP */
	return 0;
}

__initcall(holdoffs_init);