*BSD News Article 85699


Return to BSD News archive

Path: euryale.cc.adfa.oz.au!newshost.carno.net.au!harbinger.cc.monash.edu.au!news.cs.su.oz.au!metro!metro!munnari.OZ.AU!news.ecn.uoknor.edu!feed1.news.erols.com!cpk-news-hub1.bbnplanet.com!news.bbnplanet.com!su-news-hub1.bbnplanet.com!www.nntp.primenet.com!nntp.primenet.com!enews.sgi.com!news.sgi.com!news.msfc.nasa.gov!centauri.hq.nasa.gov!newsfeed.gsfc.nasa.gov!cs.umd.edu!not-for-mail
From: fwmiller@cs.umd.edu (Frank W. Miller)
Newsgroups: comp.unix.bsd.misc
Subject: Kernel profiling using Pentium timestamp counter
Date: 24 Dec 1996 12:42:02 -0500
Organization: U of Maryland, Dept. of Computer Science, Coll. Pk., MD 20742
Lines: 91
Message-ID: <59p4la$cce@yangtze.cs.umd.edu>
NNTP-Posting-Host: yangtze.cs.umd.edu
NNTP-Posting-User: fwmiller
Xref: euryale.cc.adfa.oz.au comp.unix.bsd.misc:1865


I've been trying to do some profiling of FreeBSD and BSDi using the
Pentium timestamp counter.  I am having a bizarre result.  Consider the
following piece of code:

void
tscprof(int i)
{
    int s;

    if (fp_tscprof != NULL) {
        s = splhigh();
        _tscread(&(tscproftab[i][iteration]));
        splx(s);

        if (i == (TSCPROF_POINTS - 1))
            iteration = (iteration + 1) % TSCPROF_ITERATIONS;
    }
}


This is the routine I use to cause a data point to be generated.  Basically,
I keep an array of data points during the run and then dump them to a
file when its over, sorta gprofy, but with better timer resolution.  The
_tscread() routine follows:

        .file           "tsc.s"
        .text

        .globl          __tscread
__tscread:
        pushl           %ebp
        movl            %esp, %ebp

        movl            8(%ebp), %edi

        /* Opcode for reading Pentium timestamp counter */
        .byte           0x0f
        .byte           0x31

        movl            %edx, (%edi)
        addl            $4, %edi
        movl            %eax, (%edi)

        leave
        ret
        .align          2, 0x90


This routine will read 64 bits of the timestamp counter and put them in
a structure like this:

typedef struct tsc {
    u_int hi;
    u_int lo;
} *tsc_t;


I have inserted two calls into the read() function (called to service
a read() system call) in sys_generic.c

tscprof(0);

just after the beginning of the function and

tscprof(1);

just before the return statements.


Now, here's the problem.  I know this code works, I've run it standalone
on the Pentium with no trouble.  I also know that this code works fine
inside the BSD kernels when the tscread() routine is commented out.  When
leave the tscread() call in tscprof(), every time the routine is called,
I get an error that says "Use logout to logout." printed on the console
where the read() system call is executing.  Then at the end, the console
does indeed logout.  It also appears that all the read calls are exiting
the read() function in sys_generic.c with an error code EBADF.

So, can anybody give me a clue about this?  Is the tsc interacting with
the registers in some funky way that causes an error?

Thanks in advance.

Later,
FM

-- 
Frank W. Miller                           Department of Computer Science
fwmiller@cs.umd.edu                 University of Maryland, College Park
http://www.cs.umd.edu/~fwmiller             College Park, Maryland 20742