Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-6
Quoted 2 lines
on SMP, latencytest + all IRQ threads (and ksoftirqd) at prio 99 +
PREEMPT_RTis not comparable toPREEMPT_DESKTOP(with no IRQ threading).
Of course they are comparable. You may not consider it a FAIR comparison, but they are comparable. I maintain the comparison shows the increased overhead of IRQ threading - you maintain it is an "inverse scenario" which I don't buy.
Quoted 5 lines
The -RT kernel will 'split' hardirq and softirq workloads and migrate them to different CPUs - giving them a higher total throughput. Also, on
PREEMPT_DESKTOPthe IRQs will most likely go to one CPU only, and most softirq processing will be concentrated on that CPU too. Furthermore, the -RT kernel will agressively distribute highprio RT tasks.
Now wait a minute, how does -RT do that IRQ splitting? From what I recall (I don't have RT up right now) taskset indicated all the IRQ tasks were wired to CPU 0 and the only opportunity for splitting was with ksoftirqd/0 and /1. I confirmed that by looking at the "last CPU" in top.
When I tried to change the CPU affinity of those IRQ tasks (to use both CPU's), I got error messages. One of the responses you made at that time was...
Quoted 4 lines
Quoted 1 line
If setting it to 3 is REALLY BAD, perhaps we should prevent it.
it's just like setting ksoftirqd's affinity. I agree that it's nasty, but there's no easy way right now.
Has this behavior changed in the last three weeks?
For a CONFIG_DESKTOP data point, let's take a look at the latency traces I just made from -12PK.
CPU 0 - 10, 14, 16 - 38, 40 - 43,
CPU 1 - 00 - 09, 11 - 13, 15, 39, 44
let's see - 45 total traces, 29 for CPU 0 and 16 for CPU 1. Not quite evenly balanced but not all on one CPU either (the data IS bursty though). The common_interrupt trace appears to show up only on CPU 0, but the latency traces are definitely on both CPU's.
Quoted 4 lines
latencytest under your priority setup measures an _inverse_ scenario. (a CPU hog executing at a lower priority than all IRQ traffic) I'd not be surprised at all if it had higher latencies under -RT than under
PREEMPT_DESKTOP.
Why "higher latencies"? And do you mean
- more short latencies (I'm counting a lot of just over 100 usec delays)
OR
- longer overall latencies (which I am not expecting but seeing)
OR
something else?
Let's look at the possible scenarios:
[PK refers to "Preemptible Kernel - PREEMPT_DESKTOP" w/o IRQ threading] [RT refers to PREEMPT_RT with the IRQ # and ksoftirqd/# threads at RT 99]
[1] A single interrupt comes in and latencytest is NOT on the CPU
that services the interrupt. In the case of PK, latencytest is unaffected. In the case of RT, latencytest is affected ONLY if the IRQ # thread or ksoftidqd/# thread is on the CPU with latencytest. In that case, latencytest is pushed to the other CPU. That switch takes some TBD amount of time and is counted by latencytest only if it exceeds 100 usec.
[2] A single interrupt comes in and latencytest is on the CPU that
services the interrupt. In the case of PK, latencytest is preempted for the duration of the interrupt and resumes. In the case of RT, latencytest is rescheduled on the other CPU (or not) once we reach the place where we are ready to thread the IRQ. I would think RT should do better in this case but am not sure.
[3] A series of interrupts comes in. In PK what I see is several
sequential delays up to 1/2 msec or so (and have traces that show that behavior). In RT I would expect a shorter latency period (if both CPU's are busy with IRQ's or not) than PK [though I don't have traces for this since if I cross CPU's the trace doesn't get recorded].
I don't see how RT should have worse numbers in these scenarios unless the overhead is more (or I'm counting more trivial latencies) than in PK. I would expect to see in the RT case a shorter maximum delay (which alas I do NOT see).
Quoted 6 lines
It's not clear-cut which one 'wins' though: because
even this inverse scenario will have benefits in the -RT case: due toSCHED_OTHERworkloads not interfering with this lower-prio RT task as much. But i'd expect there to be a constant moving of the 'benchmark result' forward and backwards, even if -RT only improves things - this is the nature of such an inverse priority setup.
Not quite sure what you mean by this.
Quoted 9 lines
so this setup generates two conflicting parameters which are inverse to each other, and the 'sum' of these two parameters ends up fluctuating wildly. Pretty much like the results you are getting. The two parameters
are: latency of the prio 30 task, and latency of the highprio tasks. The better the -RT kernel gets, the better the prio 30 tasks's priorities get relative toSCHED_OTHERtasks - but the worse they also get, due to the better handling of higher-prio tasks. Where the sum ends, whether it's a "win" or a "loss" depends on the workload, how much highprio activity the lowprio threads generate, etc.
I don't see how this rationale is relevant - the amount of work for IRQ activities that is generated by each workload should be similar. Its one of the reasons I run the same tests over and over again.
If I create a 750 Mbyte file (one of the stress test cases), I should be doing a series of disk writes and interrupts. Both RT and PK should do about the same work to create that file. So the overhead on latencytest should be about the same for both RT and PK. If the overhead is not the same, something is wrong.
If I look at the max latency:
RT 3.90
PK 1.91 (both cases nominal is 1.16 msec)
Quoted 1 line
From the scenarios I described above, I don't see why this result should
have occurred. Certainly nothing that should cause a delay of over two msec on a roughly one msec task.
If I look at the % within 100 usec measure:
RT 87% within 100 usec, 97% within 200 usec (360 seconds elapsed) PK 67% within 100 usec, 96% within 200 usec (57 seconds elapsed)
[note 250,000 samples in 360 seconds is 694 samples per second]
Quoted 1 line
From a percentage point of view, this looks bad for PK but if I
factor in the elapsed time I get...
- PK interrupted latencytest about 13000 times
- RT interrupted latencytest about 32000 times
I am not sure how much of this is due to the workload (disk writes) or due to the elapsed time aspects.
--Mark H Johnson
<mailto:[email protected]>
Quoted 8 lines · * [email protected] <[email protected]> wrote:
When I tried to change the CPU affinity of those IRQ tasks (to use both CPU's), I got error messages. One of the responses you made at that time was...
Quoted 4 lines
Quoted 1 line
If setting it to 3 is REALLY BAD, perhaps we should prevent it.
it's just like setting ksoftirqd's affinity. I agree that it's nasty, but there's no easy way right now.
Has this behavior changed in the last three weeks?
nope, you are right, PK and RT should be more or less comparable.
the moment we get a proper trace of one such 3msec delay we ought to see what's happening.
Quoted 8 lines
For a
CONFIG_DESKTOPdata point, let's take a look at the latency traces I just made from -12PK.
CPU 0 - 10, 14, 16 - 38, 40 - 43,
CPU 1 - 00 - 09, 11 - 13, 15, 39, 44
let's see - 45 total traces, 29 for CPU 0 and 16 for CPU 1. Not quite evenly balanced but not all on one CPU either (the data IS bursty though). Thecommon_interrupttrace appears to show up only on CPU 0, but the latency traces are definitely on both CPU's.
havent gotten these yet, but from your description i'd guess that the CPU#1 latencies would be softirq processing latencies (those occur on both CPUs).
Quoted 11 lines
Quoted 4 lines
latencytest under your priority setup measures an _inverse_ scenario. (a CPU hog executing at a lower priority than all IRQ traffic) I'd not be surprised at all if it had higher latencies under -RT than under
PREEMPT_DESKTOP.Why "higher latencies"? And do you mean
- more short latencies (I'm counting a lot of just over 100 usec delays)
OR
- longer overall latencies (which I am not expecting but seeing)
OR
something else?
i meant "longer overall latencies" - but this was based on the mistaken theory of IRQ threads wandering between CPUs, which they dont do.
Quoted 11 lines
Let's look at the possible scenarios:
[PK refers to "Preemptible Kernel -PREEMPT_DESKTOP" w/o IRQ threading] [RT refers toPREEMPT_RTwith the IRQ # and ksoftirqd/# threads at RT 99][1] A single interrupt comes in and latencytest is NOT on the CPU
that services the interrupt. In the case of PK, latencytest is unaffected. In the case of RT, latencytest is affected ONLY if the IRQ # thread or ksoftidqd/# thread is on the CPU with latencytest. In that case, latencytest is pushed to the other CPU. That switch takes some TBD amount of time and is counted by latencytest only if it exceeds 100 usec.
i'd say that such a bounce doesnt happen on RT either, because, as you've found out, all IRQ threads are bound to CPU#0.
Quoted 6 lines
[2] A single interrupt comes in and latencytest is on the CPU that
services the interrupt. In the case of PK, latencytest is preempted for the duration of the interrupt and resumes. In the case of RT, latencytest is rescheduled on the other CPU (or not) once we reach the place where we are ready to thread the IRQ. I would think RT should do better in this case but am not sure.
yes, in the RT case latencytest should be pushed to the other CPU most of the time. (unless a higher-prio [ksoftirqd] task is running on the other CPU)
Quoted 5 lines
[3] A series of interrupts comes in. In PK what I see is several
sequential delays up to 1/2 msec or so (and have traces that show that behavior). In RT I would expect a shorter latency period (if both CPU's are busy with IRQ's or not) than PK [though I don't have traces for this since if I cross CPU's the trace doesn't get recorded].
wrt. the 'trace doesnt get recorded' issue, it ought to work fine if you have wakeup_timing enabled. (even when using user-triggered tracing.) I.e. your user task should be traced across migrations too. (if not then it's a tracer bug.)
Quoted 4 lines
I don't see how RT should have worse numbers in these scenarios unless the overhead is more (or I'm counting more trivial latencies) than in PK. I would expect to see in the RT case a shorter maximum delay (which alas I do NOT see).
yep, i'd expect this too.
what i was thinking about wrt. migrations was this: the total throughput of interrupts could be higher on -RT, because of the better distribution of RT tasks between CPUs. Higher IRQ throughput means less CPU time left for the CPU-loop. (and also, consequently, bigger latencies measured in the CPU-loop.) But since all IRQ threads are in essence bound to CPU#0, this scenario cannot occur.
if the CPU overhead of -RT is dramatically higher (especially due to debugging code that only triggers in the -RT kernels) then we could see a similar effect: the same amount of SCHED_OTHER processing generates a higher amount of prio-99 activities than it does under the -PK kernel, and hence the CPU time left for the CPU loop is lower as well. (and also, bigger latencies are generated in the CPU loop.)
Quoted 7 lines
If I look at the max latency:
RT 3.90
PK 1.91 (both cases nominal is 1.16 msec)From the scenarios I described above, I don't see why this result should have occurred. Certainly nothing that should cause a delay of over two msec on a roughly one msec task.
well, if IRQ threads and ksoftirqd comes in at the wrong moment, it's prio 99 and could keep running for a long time. But no, i'd not expect such a big difference either, it's the same workload after all.
Quoted 3 lines
If I look at the % within 100 usec measure:
RT 87% within 100 usec, 97% within 200 usec (360 seconds elapsed) PK 67% within 100 usec, 96% within 200 usec (57 seconds elapsed)
(this is the elapsed time of the prio ~30 CPU-loop, right?)
this smells too. There's one aspect of -RT that could starve lower-prio RT tasks: if a high-prio RT task blocks on a mutex/semaphore then it boosts whatever lowprio task is using that mutex currently. But this means that it's boosted to prio 99 - preempting the prio 30 task. So this means that depending on the level of contention, roughly the same amount of time spent
in the PK case the prio 99 task would simply block, and the prio 30 task could run, and you dont count this in your metrics, you only count the 'bad' effect: that the prio 30 task runs worse, you dont count the 'good' effect: that the prio 99 task runs better. This is why i think it's unfair to only measure the 'middle priority layer', while not counting improvements to the 'high priority layer'.
this theory is still a bit weak though to be the sole explanation: if this were the case then we should see a decrease in total elapsed time of the SCHED_OTHER workloads, right?
but 360 seconds vs. 57 seconds still sounds like alot... Perhaps we should add 'CPU usage per priority level' statistics fields to /proc/stat, or something like that? Perhaps even a 'CPU time spent while boosted' field, to find out how the effective priority levels shift due to PI.
Ingo
PATCH 1/1 Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15
Quoted 1 line · Ingo Molnar
this smells too. [...]
found two brown-paperbag bugs that caused bad latencies in the -RT
kernel: when i added PREEMPT_DIRECT (which first showed up in -32-10) i also added a missed-reschedule bug to try_to_wake_up() and to mutex/semaphore-unlock (__up()). Oops.
i dont think this bug could explain a msec-range latency because the syscall return path should catch the missed reschedule and it would need continuous syscall execution in the milliseconds range by a lowprio task for a latency to be transported to latencytest, but certainly the bug doesnt help latencies. The -32-15 kernel can be downloaded from the usual place:
http://redhat.com/~mingo/realtime-preempt/
other changes in -32-15: more work on the tracer, cleaner trace output and the tracing of syscall entries and returns, with arguments and return values displayed as well (i.e. a simple strace variant). Here is how a syscall now looks like in /proc/latency_trace:
loop-tes-3885 0.... 100µs > sys_getppid (002fcffc 00000001 0000007b) loop-tes-3885 0.... 101µs+: sys_getppid (sysenter_past_esp) loop-tes-3885 0d... 103µs < (3868)
'< (return-val)' is the syscall return value, '> sys_name(params)' is the syscall itself. (note that the return path is also used by interrupts, so it's not purely a syscall-return point) This makes it easier to track userspace execution.
Ingo
Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15
Quoted 2 lines · Ingo Molnar
Quoted 1 line · Ingo Molnar
this smells too. [...]
Humm, something else does too Ingo. Amanda failed on this machine last night, and so did an amcheck just now, returning this:
[amanda@coyote driver]$ amcheck Daily
Amanda Tape Server Host Check
-----------------------------
Holding disk /dumps: 26444 MB disk space available, using 25944 MB
amcheck-server: slot 8: date 20041210 label Dailys-8 (active tape)
amcheck-server: slot 9: date 20041124 label Dailys-9 (exact label match)
NOTE: skipping tape-writable test
Tape Dailys-9 label ok
Server check took 0.386 seconds
Amanda Backup Client Hosts Check
--------------------------------
WARNING: coyote: selfcheck reply timed out.
Client check: 2 hosts checked in 22.199 seconds, 1 problem found
(brought to you by Amanda 2.4.5b1-20041122)
------------------
This was while running 32-12, which otherwise feels good and gave me no other indication of a problem. I've also looked at the log, but its silent on this subject. I'll get the latest and try it.
Quoted 35 lines
found two brown-paperbag bugs that caused bad latencies in the -RT
kernel: when i addedPREEMPT_DIRECT(which first showed up in -32-10) i also added a missed-reschedule bug totry_to_wake_up()and to mutex/semaphore-unlock (__up()). Oops.i dont think this bug could explain a msec-range latency because the syscall return path should catch the missed reschedule and it would need continuous syscall execution in the milliseconds range by a lowprio task for a latency to be transported to latencytest, but certainly the bug doesnt help latencies. The -32-15 kernel can be downloaded from the usual place:
http://redhat.com/~mingo/realtime-preempt/
other changes in -32-15: more work on the tracer, cleaner trace output and the tracing of syscall entries and returns, with arguments and return values displayed as well (i.e. a simple strace variant). Here is how a syscall now looks like in
/proc/latency_trace:loop-tes-3885 0.... 100µs >
sys_getppid(002fcffc000000010000007b) loop-tes-3885 0.... 101µs+:sys_getppid(sysenter_past_esp) loop-tes-3885 0d... 103µs < (3868)'< (return-val)' is the syscall return value, '>
sys_name(params)' is the syscall itself. (note that the return path is also used by interrupts, so it's not purely a syscall-return point) This makes it easier to track userspace execution.Ingo
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Signature · 8 lines
Cheers, Gene "There are four boxes to be used in defense of liberty: soap, ballot, jury, and ammo. Please use in that order." -Ed Howdershelt (Author) 99.30% setiathome rank, not too shabby for a WV hillbilly Yahoo.com attorneys please note, additions to this message by Gene Heskett are: Copyright 2004 by Maurice Eugene Heskett, all rights reserved.
Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15
Quoted 23 lines · Gene Heskett
Quoted 2 lines · Ingo Molnar
Quoted 1 line · Ingo Molnar
this smells too. [...]
Humm, something else does too Ingo. Amanda failed on this machine last night, and so did an amcheck just now, returning this:
[amanda@coyote driver]$ amcheck Daily
Amanda Tape Server Host Check
-----------------------------
Holding disk /dumps: 26444 MB disk space available, using 25944 MB
amcheck-server: slot 8: date 20041210 label Dailys-8 (active tape)
amcheck-server: slot 9: date 20041124 label Dailys-9 (exact label match)
NOTE: skipping tape-writable test
Tape Dailys-9 label ok
Server check took 0.386 secondsAmanda Backup Client Hosts Check
--------------------------------
WARNING: coyote: selfcheck reply timed out.
Client check: 2 hosts checked in 22.199 seconds, 1 problem found
Quoted 5 lines
(brought to you by Amanda 2.4.5b1-20041122)
------------------
This was while running 32-12, which otherwise feels good and gave me no other indication of a problem. I've also looked at the log, but its silent on this subject. I'll get the latest and try it.
Ok, the 32-18 is up and running, and it appears that amanda is not so unhappy now as I seem to have a hand launched session thats running nominally now.
To toss in a few more items, I noted that I had several copies of amandad, and a copy of self-check that were getting 0 cpu according to htop. They were killable however, and re-running the amcheck again left them behind.
Another factoid. kpm, the kde version of htop, was unable to display a process table listing while -12 was running.
32-18 seems to have restored all those to normal.
Is there a way I can run tvtime without making /var/log/messages bigger by about 20k a minute with those 3 line reports it apparently spits out for every frame of tv? These patches aren't apparently doing anything for the problem one way or the other, so AFAIAC the constant flow messages are a waste of time and may even be causing their own problem with the constant traffic to the logfile..
Quoted 37 lines
Quoted 37 lines
found two brown-paperbag bugs that caused bad latencies in the -RT
kernel: when i addedPREEMPT_DIRECT(which first showed up in -32-10) i also added a missed-reschedule bug totry_to_wake_up()and to mutex/semaphore-unlock (__up()). Oops.i dont think this bug could explain a msec-range latency because the syscall return path should catch the missed reschedule and it would need continuous syscall execution in the milliseconds range by a lowprio task for a latency to be transported to latencytest, but certainly the bug doesnt help latencies. The -32-15 kernel can be downloaded from the usual place:
http://redhat.com/~mingo/realtime-preempt/
other changes in -32-15: more work on the tracer, cleaner trace output and the tracing of syscall entries and returns, with arguments and return values displayed as well (i.e. a simple strace variant). Here is how a syscall now looks like in
/proc/latency_trace:loop-tes-3885 0.... 100µs >
sys_getppid(002fcffc000000010000007b) loop-tes-3885 0.... 101µs+:sys_getppid(sysenter_past_esp) loop-tes-3885 0d... 103µs < (3868)'< (return-val)' is the syscall return value, '>
sys_name(params)' is the syscall itself. (note that the return path is also used by interrupts, so it's not purely a syscall-return point) This makes it easier to track userspace execution.Ingo
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected] More majordomo info at
http://vger.kernel.org/majordomo-info.html Please read the FAQ at
http://www.tux.org/lkml/
Signature · 8 lines
Cheers, Gene "There are four boxes to be used in defense of liberty: soap, ballot, jury, and ammo. Please use in that order." -Ed Howdershelt (Author) 99.30% setiathome rank, not too shabby for a WV hillbilly Yahoo.com attorneys please note, additions to this message by Gene Heskett are: Copyright 2004 by Maurice Eugene Heskett, all rights reserved.
Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15
In reply to Ingo MolnarQuoted 4 lines · Ingo Molnar
The -32-15 kernel can be downloaded from the
usual place:
Any chance this will work on x86_64 anytime soon? Not necessarily PREEMPT_RT, it would be nice if PREEMPT_DESKTOP worked. You mentioned a few weeks ago it needs the timer interrupt threading changes.
CC arch/x86_64/kernel/asm-offsets.s
In file included from include/asm/timex.h:12,
from include/linux/timex.h:61,
from include/linux/sched.h:11,
from arch/x86_64/kernel/asm-offsets.c:7:include/asm/vsyscall.h:55: error: conflicting types for \'xtime_lock\' include/linux/time.h:83: error: previous declaration of \'xtime_lock\' was hereinclude/asm/vsyscall.h:55: error: conflicting types for \'xtime_lock\' include/linux/time.h:83: error: previous declaration of \'xtime_lock\' was here
make[1]: *** [arch/x86_64/kernel/asm-offsets.s] Error 1
make: *** [arch/x86_64/kernel/asm-offsets.s] Error 2
Lee