Module Profiling Problem

Chris K Cockrum (kernel@cockrum.net)
Mon, 22 Jan 2001 18:44:28 -0500


I have been developing a driver for an audio card and encountered a problem
which I have duplicated in the test code below. My problem is that when
trying to profile a section of code in a kernel module I get erratic
results. My cycle counts are sometimes 73xxx cycles more that I expect
them to be. Does anyone know what could be causing this?

Thanks in Advance,
Chris K Cockrum
iBiquity Digital Corp.
http://www.ibiquity.com

Running Linux 2.4.0 on a Tyan Tiger Dual 800MHz Motherboard w/133MHz Bus

#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/sched.h>
#include <asm/smplock.h>

/* Declare Spinlock */
spinlock_t testlock;

int init_module(void)
{
unsigned long long starttime,stoptime;

unsigned int lockflags,n,tempval=20000;

spin_lock_init(&testlock);

for (n=0;n<40;n++)
{
spin_lock_irqsave(&testlock,lockflags);

/* Clear Interrupt Flag */
__asm__ __volatile__ ("cli");

/* Get CPU Clock */
__asm__ __volatile__ ("rdtsc\n\t" \
"movl %%eax, (%%ecx)\n\t" \
"movl %%edx, 4(%%ecx)"\
::"c" (&starttime));

/* Waste Time-Register Moves Looped tempval Times */
__asm__ __volatile__ ("loop: movl %%ecx,%%eax\t\n" \
" decl %%ecx\t\n" \
" jnz loop" \
:: "c" (tempval) : "%eax");

/* Get CPU Clock */
__asm__ __volatile__ ("rdtsc\n\t" \
"movl %%eax, (%%ecx)\n\t" \
"movl %%edx, 4(%%ecx)"\
::"c" (&stoptime));

spin_unlock_irqrestore(&testlock,lockflags);

printk(KERN_DEBUG "Test: 0x%08X:%08X - %d Cycles\n", \
(unsigned int) (((stoptime-starttime)>>32)&0xFFFFFFFF), \
(unsigned int) ((stoptime-starttime) &0xFFFFFFFF), \
(unsigned int) ((stoptime-starttime) &0xFFFFFFFF) );

}
return 0;
}

void cleanup_module(void)
{
printk(KERN_DEBUG "Unloaded\n");
}

Results:

Test: 0x00000000:0000EA94 - 60052 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:00020977 - 133495 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:00020997 - 133527 Cycles
Test: 0x00000000:0002098F - 133519 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:00020976 - 133494 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0002098A - 133514 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0002098E - 133518 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles
Test: 0x00000000:0002098A - 133514 Cycles
Test: 0x00000000:0000EA87 - 60039 Cycles

-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
Please read the FAQ at http://www.tux.org/lkml/