Mailing List Archive

Selective system profiling
Hello everyone,

Here's my situation:

I'm pushing data in chunks of 1316 bytes to a PCI device at 38 Mbit/s.
In other words, I write 1316 bytes to the device every 277 microseconds.

I've noticed that the latency of this operation varies immensely. Most
of the time it completes in 50-80 microseconds, but there are occasions
when it takes several milliseconds (I've even logged 23 ms).

The pseudo-code looks like this:

deadline = now;

while ( 1 )
{
deadline += 277 µs
sleep_until(deadline)
t0 = now;
write 1316 bytes to PCI device
t1 = now;
if (t1-t0 > 100 µs) scream & panic
}

Relevant (?) information about the setup:

I'm running a PREEMPT_RT kernel with high-resolution timers.
(Specifically 2.6.20.7-rt8)
http://rt.wiki.kernel.org/index.php/Main_Page
HZ=100
The process is in SCHED_RR with priority 75.
The only "process" (?) with higher priority is posix_cpu_timer.
write() is implemented as an ioctl in the driver.
You might think that write() blocks when the buffers on the PCI board
are full, but I am 99.9% sure that the buffers are never full.


Here's my question:

When my process comes back from a write operation, and I find that I
have been blocked for more than X ms, can I call a function from a
system profiler (oprofile perhaps?) to know exactly where in the kernel
the CPU has been for the last X ms, and how much time has been spent in
each function, either sleeping or doing something?

Regards.
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: Selective system profiling [ In reply to ]
John Sigler wrote:

> Hello everyone,
>
> Here's my situation:
>
> I'm pushing data in chunks of 1316 bytes to a PCI device at 38 Mbit/s.
> In other words, I write 1316 bytes to the device every 277 microseconds.
>
> I've noticed that the latency of this operation varies immensely. Most
> of the time it completes in 50-80 microseconds, but there are occasions
> when it takes several milliseconds (I've even logged 23 ms).
>
> The pseudo-code looks like this:
>
> deadline = now;
>
> while ( 1 )
> {
> deadline += 277 µs
> sleep_until(deadline)
> t0 = now;
> write 1316 bytes to PCI device
> t1 = now;
> if (t1-t0 > 100 µs) scream & panic
> }
>
> Relevant (?) information about the setup:
>
> I'm running a PREEMPT_RT kernel with high-resolution timers.
> (Specifically 2.6.20.7-rt8)
> http://rt.wiki.kernel.org/index.php/Main_Page
> HZ=100
> The process is in SCHED_RR with priority 75.
> The only "process" (?) with higher priority is posix_cpu_timer.
> write() is implemented as an ioctl in the driver.
> You might think that write() blocks when the buffers on the PCI board
> are full, but I am 99.9% sure that the buffers are never full.
>
>
> Here's my question:
>
> When my process comes back from a write operation, and I find that I
> have been blocked for more than X ms, can I call a function from a
> system profiler (oprofile perhaps?) to know exactly where in the kernel
> the CPU has been for the last X ms, and how much time has been spent in
> each function, either sleeping or doing something?

Perhaps I could take this matter to a different list?
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/