Measuring system call times, elapsed and cpu

Measuring system call times, elapsed and cpu

[Mike Mason]

I'm writing a script that attempts to measure how long it takes system calls to finish.  It uses gettimeofday_ns() to get the time at entry and exit, then calculates the delta.  Simple.  It occurred me, however, that a system call can start on one cpu and finish on another.  Now I'm wondering if I can rely on gettimeofday_ns() for this type of measurement.  If not, is there a better way to do this?

I'd also like to break down the system call latency into cpu and wait times.  I thought of calculating the delta of utime+stime from task_struct to get cpu time, then subtracting that from the overall delta to get wait time.  Should this work or am I missing something?

Thanks,
Mike

RE: Measuring system call times, elapsed and cpu

[Stone, Joshua I]

Mike Mason wrote:
> I'm writing a script that attempts to measure how long it takes
> system calls to finish.  It uses gettimeofday_ns() to get the time at
> entry and exit, then calculates the delta.  Simple.  It occurred me,
> however, that a system call can start on one cpu and finish on
> another.  Now I'm wondering if I can rely on gettimeofday_ns() for
> this type of measurement.  If not, is there a better way to do this?

It should work, with the caveat of bug #3916.  The gettimeofday results
are system time, so they should be consistent across CPUs.

> I'd also like to break down the system call latency into cpu and wait
> times.  I thought of calculating the delta of utime+stime from
> task_struct to get cpu time, then subtracting that from the overall
> delta to get wait time.  Should this work or am I missing something?

This will include any time while you were context-switched away -- is
that your intention?


Josh

Re: Measuring system call times, elapsed and cpu

[Mike Mason]

Stone, Joshua I wrote:
> Mike Mason wrote:
>> I'm writing a script that attempts to measure how long it takes
>> system calls to finish.  It uses gettimeofday_ns() to get the time at
>> entry and exit, then calculates the delta.  Simple.  It occurred me,
>> however, that a system call can start on one cpu and finish on
>> another.  Now I'm wondering if I can rely on gettimeofday_ns() for
>> this type of measurement.  If not, is there a better way to do this?
> 
> It should work, with the caveat of bug #3916.  The gettimeofday results
> are system time, so they should be consistent across CPUs.
> 
>> I'd also like to break down the system call latency into cpu and wait
>> times.  I thought of calculating the delta of utime+stime from
>> task_struct to get cpu time, then subtracting that from the overall
>> delta to get wait time.  Should this work or am I missing something?
> 
> This will include any time while you were context-switched away -- is
> that your intention?

Poor choice of words on my part.  I meant cpu and non-cpu time, not cpu and wait time.

Now that I think about it some more, utime and stime aren't fine grained enough.  They're only updated every timer tick.  Is there some other way to measure real cpu time between function entry and exit?

Mike

> 
> 
> Josh

RE: Measuring system call times, elapsed and cpu

[Stone, Joshua I]

Mike Mason wrote:
> Now that I think about it some more, utime and stime aren't fine
> grained enough.  They're only updated every timer tick.  Is there
> some other way to measure real cpu time between function entry and
> exit?

CFS offers better precision through task_utime() and task_stime(), but
those don't appear to be exported.

Josh