Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Mark_H_Johnson]

>The -32-15 kernel can be downloaded from the
>usual place:
>
> http://redhat.com/~mingo/realtime-preempt/

By the time I started today, the directory had -18 so that is what I built
with. Here are some initial results from running cpu_delay (the simple
RT test / user tracing) on a -18 PREEMPT_RT kernel. Have not started
any of the stress tests yet.

To recap, all IRQ # tasks, ksoftirqd/# and events/# tasks are RT FIFO
priority 99. The test program runs at RT FIFO 30 and should use about
70% of the CPU time on the two CPU SMP system under test.

[1] I still do not get traces where cpu_delay switches CPU's. I only
get trace output if it starts and ends on a single CPU. I also had
several cases where I "triggered" a trace but no output - I assume
those are related symptoms. For example:

# ./cpu_delay 0.000100
Delay limit set to 0.00010000 seconds
calibrating loop ....
time diff= 0.504598 or 396354830 loops/sec.
Trace activated with 0.000100 second delay.
Trace triggered with 0.000102 second delay. [not recorded]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000164 second delay. [not recorded]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000132 second delay. [00]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000128 second delay. [01]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000144 second delay. [not recorded]
Trace triggered with 0.000355 second delay. [02]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000101 second delay. [not recorded]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000126 second delay. [not recorded]
Trace triggered with 0.000205 second delay. [not recorded]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000147 second delay. [03]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000135 second delay. [04]
Trace triggered with 0.000110 second delay. [not recorded]
Trace triggered with 0.000247 second delay. [05]
Trace triggered with 0.000120 second delay. [06]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000107 second delay. [07]
Trace triggered with 0.000104 second delay. [not recorded]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000100 second delay. [08]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000201 second delay. [09]

# chrt -f 1 ./get_ltrace.sh 50
Current Maximum is 4965280, limit will be 50.
Resetting max latency from 4965280 to 50.
No new latency samples at Fri Dec 10 11:01:22 CST 2004.
No new latency samples at Fri Dec 10 11:01:32 CST 2004.
No new latency samples at Fri Dec 10 11:01:42 CST 2004.
No new latency samples at Fri Dec 10 11:01:53 CST 2004.
No new latency samples at Fri Dec 10 11:02:03 CST 2004.
No new latency samples at Fri Dec 10 11:02:13 CST 2004.
New trace 0 w/ 117 usec latency.
Resetting max latency from 117 to 50.
No new latency samples at Fri Dec 10 11:02:35 CST 2004.
No new latency samples at Fri Dec 10 11:02:45 CST 2004.
New trace 1 w/ 99 usec latency.
Resetting max latency from 99 to 50.
New trace 2 w/ 248 usec latency.
Resetting max latency from 248 to 50.
New trace 3 w/ 146 usec latency.
Resetting max latency from 146 to 50.
New trace 4 w/ 134 usec latency.
Resetting max latency from 134 to 50.
New trace 5 w/ 250 usec latency.
Resetting max latency from 250 to 50.
New trace 6 w/ 120 usec latency.
Resetting max latency from 120 to 50.
New trace 7 w/ 105 usec latency.
Resetting max latency from 105 to 50.
New trace 8 w/ 91 usec latency.
Resetting max latency from 91 to 50.
New trace 9 w/ 200 usec latency.

For the most part, the elapsed times in the traces match closely to what
was measured by the application.

[2] The all CPU traces appear to show some cases where both ksoftirqd
tasks are active during a preemption of the RT task. That is expected
with my priority settings. [though the first trace shows BOTH getting
activated within 2 usec!]

[3] Some traces show information on both CPU's and then a long period
with no traces from the other. Here is an example...

preemption latency trace v1.1.4 on 2.6.10-rc2-mm3-V0.7.32-18RT
--------------------------------------------------------------------
 latency: 99 us, #275/275, CPU#0 | (M:rt VP:0, KP:1, SP:1 HP:1 #P:2)
    -----------------
    | task: cpu_delay-3556 (uid:0 nice:0 policy:1 rt_prio:30)
    -----------------
 => started at: <00000000>
 => ended at:   <00000000>

                 _------=> CPU#
                / _-----=> irqs-off
               | / _----=> need-resched
               || / _---=> hardirq/softirq
               ||| / _--=> preempt-depth
               |||| /
               |||||     delay
   cmd     pid ||||| time  |   caller
      \   /    |||||   \   |   /
<unknown-2847  1d...    0µs : smp_apic_timer_interrupt (86a89bf 0 0)
cpu_dela-3556  0d.h1    0µs : update_process_times
(smp_apic_timer_interrupt)
cpu_dela-3556  0d.h1    0µs : account_system_time (update_process_times)
cpu_dela-3556  0d.h1    0µs : check_rlimit (account_system_time)
<unknown-2847  1d.h.    0µs : update_process_times
(smp_apic_timer_interrupt)
cpu_dela-3556  0d.h1    0µs : account_it_prof (account_system_time)
...
<unknown-2847  1d.h1    4µs : _raw_spin_unlock (scheduler_tick)
cpu_dela-3556  0d.h1    4µs : irq_exit (apic_timer_interrupt)
<unknown-2847  1d.h.    4µs : rebalance_tick (scheduler_tick)
cpu_dela-3556  0d..2    4µs : do_softirq (irq_exit)
cpu_dela-3556  0d..2    4µs : __do_softirq (do_softirq)
<unknown-2847  1d.h.    5µs : irq_exit (apic_timer_interrupt)
cpu_dela-3556  0d..2    5µs : wake_up_process (do_softirq)
cpu_dela-3556  0d..2    5µs : try_to_wake_up (wake_up_process)
cpu_dela-3556  0d..2    5µs : task_rq_lock (try_to_wake_up)
<unknown-2847  1d...    5µs < (0)
cpu_dela-3556  0d..2    5µs : _raw_spin_lock (task_rq_lock)
cpu_dela-3556  0d..3    6µs : activate_task (try_to_wake_up)
cpu_dela-3556  0d..3    6µs : sched_clock (activate_task)
cpu_dela-3556  0d..3    7µs : recalc_task_prio (activate_task)
cpu_dela-3556  0d..3    7µs : effective_prio (recalc_task_prio)
cpu_dela-3556  0d..3    7µs : activate_task <ksoftirq-4> (0 1):
cpu_dela-3556  0d..3    7µs : enqueue_task (activate_task)
cpu_dela-3556  0d..3    8µs : resched_task (try_to_wake_up)
cpu_dela-3556  0dn.3    8µs : __trace_start_sched_wakeup (try_to_wake_up)
cpu_dela-3556  0dn.3    8µs : try_to_wake_up <ksoftirq-4> (0 45):
cpu_dela-3556  0dn.3    9µs : _raw_spin_unlock_irqrestore (try_to_wake_up)
cpu_dela-3556  0dn.2    9µs : preempt_schedule (try_to_wake_up)
cpu_dela-3556  0dn.2    9µs : wake_up_process (do_softirq)
cpu_dela-3556  0dn.1   10µs < (0)
cpu_dela-3556  0.n.1   10µs : preempt_schedule (up)
cpu_dela-3556  0.n..   10µs : preempt_schedule (user_trace_start)
cpu_dela-3556  0dn..   11µs : __sched_text_start (preempt_schedule)
cpu_dela-3556  0dn.1   11µs : sched_clock (__sched_text_start)
cpu_dela-3556  0dn.1   11µs : _raw_spin_lock_irq (__sched_text_start)
cpu_dela-3556  0dn.1   12µs : _raw_spin_lock_irqsave (__sched_text_start)
cpu_dela-3556  0dn.2   12µs : pull_rt_tasks (__sched_text_start)
cpu_dela-3556  0dn.2   12µs : find_next_bit (pull_rt_tasks)
cpu_dela-3556  0dn.2   13µs : find_next_bit (pull_rt_tasks)
cpu_dela-3556  0d..2   13µs : trace_array (__sched_text_start)
cpu_dela-3556  0d..2   13µs : trace_array <ksoftirq-4> (0 1):
cpu_dela-3556  0d..2   15µs : trace_array <cpu_dela-3556> (45 46):
cpu_dela-3556  0d..2   16µs+: trace_array (__sched_text_start)
ksoftirq-4     0d..2   19µs : __switch_to (__sched_text_start)
ksoftirq-4     0d..2   20µs : __sched_text_start <cpu_dela-3556> (45 0):
ksoftirq-4     0d..2   20µs : finish_task_switch (__sched_text_start)
ksoftirq-4     0d..2   20µs : smp_send_reschedule_allbutself
(finish_task_switch)
ksoftirq-4     0d..2   20µs : send_IPI_allbutself
(smp_send_reschedule_allbutself)
ksoftirq-4     0d..2   21µs : __bitmap_weight (send_IPI_allbutself)
ksoftirq-4     0d..2   21µs : __send_IPI_shortcut (send_IPI_allbutself)
ksoftirq-4     0d..2   21µs : _raw_spin_unlock (finish_task_switch)
ksoftirq-4     0d..1   22µs : trace_stop_sched_switched
(finish_task_switch)
ksoftirq-4     0....   23µs : _do_softirq (ksoftirqd)
ksoftirq-4     0d...   23µs : ___do_softirq (_do_softirq)
ksoftirq-4     0....   23µs : run_timer_softirq (___do_softirq)
ksoftirq-4     0....   24µs : _spin_lock (run_timer_softirq)
ksoftirq-4     0....   24µs : __spin_lock (_spin_lock)
ksoftirq-4     0....   24µs : __might_sleep (__spin_lock)
<unknown-2847  1d...   24µs : smp_reschedule_interrupt (86a8bd8 0 0)
ksoftirq-4     0....   24µs : _down_mutex (__spin_lock)
<unknown-2847  1d...   25µs < (0)
ksoftirq-4     0....   25µs : __down_mutex (__spin_lock)
ksoftirq-4     0....   25µs : __might_sleep (__down_mutex)
ksoftirq-4     0d...   25µs : _raw_spin_lock (__down_mutex)
ksoftirq-4     0d..1   25µs : _raw_spin_lock (__down_mutex)
ksoftirq-4     0d..2   26µs : _raw_spin_lock (__down_mutex)
ksoftirq-4     0d..3   26µs : set_new_owner (__down_mutex)
ksoftirq-4     0d..3   26µs : set_new_owner <ksoftirq-4> (0 0):
ksoftirq-4     0d..3   27µs : _raw_spin_unlock (__down_mutex)
ksoftirq-4     0d..2   27µs : _raw_spin_unlock (__down_mutex)
ksoftirq-4     0d..1   27µs : _raw_spin_unlock (__down_mutex)
... no more traces from CPU 1 ...
ksoftirq-4     0....   77µs : rcu_check_quiescent_state
(__rcu_process_callbacks)
ksoftirq-4     0....   77µs : cond_resched_all (___do_softirq)
ksoftirq-4     0....   77µs : cond_resched (___do_softirq)
ksoftirq-4     0....   78µs : cond_resched (ksoftirqd)
ksoftirq-4     0....   78µs : kthread_should_stop (ksoftirqd)
ksoftirq-4     0....   78µs : schedule (ksoftirqd)
ksoftirq-4     0....   78µs : __sched_text_start (schedule)
ksoftirq-4     0...1   79µs : sched_clock (__sched_text_start)
ksoftirq-4     0...1   79µs : _raw_spin_lock_irq (__sched_text_start)
ksoftirq-4     0...1   79µs : _raw_spin_lock_irqsave (__sched_text_start)
ksoftirq-4     0d..2   80µs : deactivate_task (__sched_text_start)
ksoftirq-4     0d..2   80µs : dequeue_task (deactivate_task)
ksoftirq-4     0d..2   81µs : trace_array (__sched_text_start)
ksoftirq-4     0d..2   82µs : trace_array <cpu_dela-3556> (45 46):
ksoftirq-4     0d..2   84µs+: trace_array (__sched_text_start)
cpu_dela-3556  0d..2   86µs : __switch_to (__sched_text_start)
cpu_dela-3556  0d..2   87µs : __sched_text_start <ksoftirq-4> (0 45):
cpu_dela-3556  0d..2   87µs : finish_task_switch (__sched_text_start)
cpu_dela-3556  0d..2   87µs : _raw_spin_unlock (finish_task_switch)
cpu_dela-3556  0d..1   88µs : trace_stop_sched_switched
(finish_task_switch)
cpu_dela-3556  0d...   89µs+< (0)
cpu_dela-3556  0d...   92µs : math_state_restore (device_not_available)
cpu_dela-3556  0d...   92µs : restore_fpu (math_state_restore)
cpu_dela-3556  0d...   93µs < (0)
cpu_dela-3556  0....   93µs > sys_gettimeofday (00000000 00000000 0000007b)
cpu_dela-3556  0....   93µs : sys_gettimeofday (sysenter_past_esp)
cpu_dela-3556  0....   94µs : user_trace_stop (sys_gettimeofday)
cpu_dela-3556  0...1   94µs : user_trace_stop (sys_gettimeofday)
cpu_dela-3556  0...1   95µs : _raw_spin_lock_irqsave (user_trace_stop)
cpu_dela-3556  0d..2   95µs : _raw_spin_unlock_irqrestore (user_trace_stop)

If I read this right, we tried to reschedule cpu_delay on CPU #1 (at
24 usec) but it never happened and cpu_delay was still "ready to run"
on CPU #0 70 usec later.

[4] I have a trace where cpu_delay was bumped off of CPU #1 at 20 usec
while the X server (not RT) was the active process on CPU #0 for another
130 usec (several traces with preempt-depth ==0) when it finally gets
bumped by IRQ 0.

[5] More of a cosmetic problem, several traces still show the
application name as "unknown" - even for long lived processes like
ksoftirqd/0 and X.

Due to the file size, I will send the traces separately.
  --Mark

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Ingo Molnar]

* Mark_H_Johnson@raytheon.com <Mark_H_Johnson@raytheon.com> wrote:

> [1] I still do not get traces where cpu_delay switches CPU's. I only
> get trace output if it starts and ends on a single CPU. [...]

lt001.18RT/lt.02 is such a trace. It starts on CPU#1:

 <unknown-3556  1...1    0µs : find_next_bit (user_trace_start)

and ends on CPU#0:

 <unknown-3556  1...1  247µs : _raw_spin_lock_irqsave (user_trace_stop)

the trace shows a typical migration of an RT task.

(but ... i have to say the debugging overhead is horrible. Please try a
completely-non-debug-non-tracing kernel just to see the difference.)

	Ingo

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Ingo Molnar]

* Mark_H_Johnson@raytheon.com <Mark_H_Johnson@raytheon.com> wrote:

> [3] Some traces show information on both CPU's and then a long period
> with no traces from the other. Here is an example...

> <unknown-2847  1d.h.    4µs : rebalance_tick (scheduler_tick)
> <unknown-2847  1d.h.    5µs : irq_exit (apic_timer_interrupt)
> <unknown-2847  1d...    5µs < (0)

> ... no more traces from CPU 1 ...

PID 2847 returned to userspace at timestamp 5µs. Userspace then can take
an arbitrary amount of time until it calls the kernel again.

	Ingo

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Ingo Molnar]

* Mark_H_Johnson@raytheon.com <Mark_H_Johnson@raytheon.com> wrote:

> [...] I also had several cases where I "triggered" a trace but no
> output - I assume those are related symptoms. For example:
> 
> # ./cpu_delay 0.000100
> Delay limit set to 0.00010000 seconds
> calibrating loop ....
> time diff= 0.504598 or 396354830 loops/sec.
> Trace activated with 0.000100 second delay.
> Trace triggered with 0.000102 second delay. [not recorded]
> Trace activated with 0.000100 second delay.
> Trace triggered with 0.000164 second delay. [not recorded]

is the userspace delay measurement nested inside the kernel-based
method? I.e. is it something like:

	gettimeofday(0,1);
	timestamp1 = cycles();

	... loop some ...

	timestamp2 = cycles();
	gettimeofday(0,0);

and do you get 'unreported' latencies in such a case too? If yes then
that would indeed indicate a tracer bug. But if the measurement is done
like this:

	gettimeofday(0,1);
	timestamp1 = cycles();

	... loop some ...

	gettimeofday(0,0);		// [1]
	timestamp2 = cycles();		// [2]

then a delay could get inbetween [1] and [2].

OTOH if the 'loop some' time is long enough then the [1]-[2] window is
too small to be significant statistically, while your logs show a near
50% 'miss rate'.

	Ingo

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Fernando Lopez-Lezcano]

logOn Fri, 2004-12-10 at 09:49, Mark_H_Johnson@raytheon.com wrote:
> >The -32-15 kernel can be downloaded from the
> >usual place:
> >
> > http://redhat.com/~mingo/realtime-preempt/
> 
> By the time I started today, the directory had -18 so that is what I built
> with. Here are some initial results from running cpu_delay (the simple
> RT test / user tracing) on a -18 PREEMPT_RT kernel. Have not started
> any of the stress tests yet.

Something that just happened to me: running 0.7.32-14 (PREEMPT_DESKTOP)
and trying to install 0.7.32-19 from a custom built rpm package
completely hangs the machine (p4 laptop - I tried twice). No clues left
behind. If I boot into 0.7.32-9 I can install 0.7.32-19 with no
problems. 

-- Fernando

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Ingo Molnar]

* Fernando Lopez-Lezcano <nando@ccrma.Stanford.EDU> wrote:

> Something that just happened to me: running 0.7.32-14
> (PREEMPT_DESKTOP) and trying to install 0.7.32-19 from a custom built
> rpm package completely hangs the machine (p4 laptop - I tried twice).
> No clues left behind. If I boot into 0.7.32-9 I can install 0.7.32-19
> with no problems. 

does 0.7.32-19 work better if you reverse (patch -R) the loop.h and
loop.c bits (see below)?

	Ingo

--- linux/drivers/block/loop.c.orig
+++ linux/drivers/block/loop.c
@@ -378,7 +378,7 @@ static void loop_add_bio(struct loop_dev
 		lo->lo_bio = lo->lo_biotail = bio;
 	spin_unlock_irqrestore(&lo->lo_lock, flags);
 
-	up(&lo->lo_bh_mutex);
+	complete(&lo->lo_bh_done);
 }
 
 /*
@@ -427,7 +427,7 @@ static int loop_make_request(request_que
 	return 0;
 err:
 	if (atomic_dec_and_test(&lo->lo_pending))
-		up(&lo->lo_bh_mutex);
+		complete(&lo->lo_bh_done);
 out:
 	bio_io_error(old_bio, old_bio->bi_size);
 	return 0;
@@ -495,12 +495,12 @@ static int loop_thread(void *data)
 	/*
 	 * up sem, we are running
 	 */
-	up(&lo->lo_sem);
+	complete(&lo->lo_done);
 
 	for (;;) {
-		down_interruptible(&lo->lo_bh_mutex);
+		wait_for_completion_interruptible(&lo->lo_bh_done);
 		/*
-		 * could be upped because of tear-down, not because of
+		 * could be completed because of tear-down, not because of
 		 * pending work
 		 */
 		if (!atomic_read(&lo->lo_pending))
@@ -521,7 +521,7 @@ static int loop_thread(void *data)
 			break;
 	}
 
-	up(&lo->lo_sem);
+	complete(&lo->lo_done);
 	return 0;
 }
 
@@ -708,7 +708,7 @@ static int loop_set_fd(struct loop_devic
 	set_blocksize(bdev, lo_blocksize);
 
 	kernel_thread(loop_thread, lo, CLONE_KERNEL);
-	down(&lo->lo_sem);
+	wait_for_completion(&lo->lo_done);
 	return 0;
 
  out_putf:
@@ -773,10 +773,10 @@ static int loop_clr_fd(struct loop_devic
 	spin_lock_irq(&lo->lo_lock);
 	lo->lo_state = Lo_rundown;
 	if (atomic_dec_and_test(&lo->lo_pending))
-		up(&lo->lo_bh_mutex);
+		complete(&lo->lo_bh_done);
 	spin_unlock_irq(&lo->lo_lock);
 
-	down(&lo->lo_sem);
+	wait_for_completion(&lo->lo_done);
 
 	lo->lo_backing_file = NULL;
 
@@ -1153,8 +1153,8 @@ int __init loop_init(void)
 		if (!lo->lo_queue)
 			goto out_mem4;
 		init_MUTEX(&lo->lo_ctl_mutex);
-		init_MUTEX_LOCKED(&lo->lo_sem);
-		init_MUTEX_LOCKED(&lo->lo_bh_mutex);
+		init_completion(&lo->lo_done);
+		init_completion(&lo->lo_bh_done);
 		lo->lo_number = i;
 		spin_lock_init(&lo->lo_lock);
 		disk->major = LOOP_MAJOR;
--- linux/include/linux/loop.h.orig
+++ linux/include/linux/loop.h
@@ -58,9 +58,9 @@ struct loop_device {
 	struct bio 		*lo_bio;
 	struct bio		*lo_biotail;
 	int			lo_state;
-	struct semaphore	lo_sem;
+	struct completion	lo_done;
+	struct completion	lo_bh_done;
 	struct semaphore	lo_ctl_mutex;
-	struct semaphore	lo_bh_mutex;
 	atomic_t		lo_pending;
 
 	request_queue_t		*lo_queue;

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Fernando Lopez-Lezcano]

On Sun, 2004-12-12 at 22:47, Ingo Molnar wrote:
> * Fernando Lopez-Lezcano <nando@ccrma.Stanford.EDU> wrote:
> 
> > Something that just happened to me: running 0.7.32-14
> > (PREEMPT_DESKTOP) and trying to install 0.7.32-19 from a custom built
> > rpm package completely hangs the machine (p4 laptop - I tried twice).
> > No clues left behind. If I boot into 0.7.32-9 I can install 0.7.32-19
> > with no problems. 
> 
> does 0.7.32-19 work better if you reverse (patch -R) the loop.h and
> loop.c bits (see below)?

Running 0.7.32-19 (no changes) I managed to install 0.7.32-20 with no
problems... probably a problem in -14 that was somehow fixed in later
releases. 

-- Fernando

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[K.R. Foley]

Fernando Lopez-Lezcano wrote:
> On Sun, 2004-12-12 at 22:47, Ingo Molnar wrote:
> 
>>* Fernando Lopez-Lezcano <nando@ccrma.Stanford.EDU> wrote:
>>
>>
>>>Something that just happened to me: running 0.7.32-14
>>>(PREEMPT_DESKTOP) and trying to install 0.7.32-19 from a custom built
>>>rpm package completely hangs the machine (p4 laptop - I tried twice).
>>>No clues left behind. If I boot into 0.7.32-9 I can install 0.7.32-19
>>>with no problems. 
>>
>>does 0.7.32-19 work better if you reverse (patch -R) the loop.h and
>>loop.c bits (see below)?
> 
> 
> Running 0.7.32-19 (no changes) I managed to install 0.7.32-20 with no
> problems... probably a problem in -14 that was somehow fixed in later
> releases. 
> 
> -- Fernando

Possibly. I have had the occasional problem with running make install 
locking one of my systems. Rebooting and running make install again 
works fine in my case. It is by no means a regular occurrence, even 
installing 2 or 3 new kernels daily on 3 different machines.

kr

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Rui Nuno Capela]

K.R. Foley wrote:
> Fernando Lopez-Lezcano wrote:
>> On Sun, 2004-12-12 at 22:47, Ingo Molnar wrote:
>>
>>>* Fernando Lopez-Lezcano <nando@ccrma.Stanford.EDU> wrote:
>>>
>>>
>>>>Something that just happened to me: running 0.7.32-14
>>>>(PREEMPT_DESKTOP) and trying to install 0.7.32-19 from a custom built
>>>>rpm package completely hangs the machine (p4 laptop - I tried twice).
>>>>No clues left behind. If I boot into 0.7.32-9 I can install 0.7.32-19
>>>>with no problems.
>>>
>>>does 0.7.32-19 work better if you reverse (patch -R) the loop.h and
>>>loop.c bits (see below)?
>>
>>
>> Running 0.7.32-19 (no changes) I managed to install 0.7.32-20 with no
>> problems... probably a problem in -14 that was somehow fixed in later
>> releases.
>>
>> -- Fernando
>
> Possibly. I have had the occasional problem with running make install
> locking one of my systems. Rebooting and running make install again
> works fine in my case. It is by no means a regular occurrence, even
> installing 2 or 3 new kernels daily on 3 different machines.
>

Isn't this tightly related to mkinitrd sometimes hanging while on mount -o
loop, that I've been reporting a couple of times before? It used to hang
on any other time I do a new kernel install, but latetly it seems to be OK
(RT-V0.9.32-19 and -20).
-- 
rncbc aka Rui Nuno Capela
rncbc@rncbc.org

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Ingo Molnar]

* Rui Nuno Capela <rncbc@rncbc.org> wrote:

> Isn't this tightly related to mkinitrd sometimes hanging while on
> mount -o loop, that I've been reporting a couple of times before? It
> used to hang on any other time I do a new kernel install, but latetly
> it seems to be OK (RT-V0.9.32-19 and -20).

yeah, i've added Thomas Gleixner's earlier semaphore->completion
conversion to the loop device, to -19 or -18.

	Ingo

Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Esben Nielsen]

I haven't seen much traffic on real-time preemption lately. Is it due
to Christmas or lost interest?

I noticed that you changed rw-locks to behave quite diferently under
real-time preemption: They basicly works like normal locks now. I.e. there
can only be one reader task within each region. This can can however lock
the region recursively. I wanted to start looking at fixing that because
it ought to hurt scalability quite a bit - and even on UP create a few
unneeded task-switchs. However, the more I think about it the bigger the 
problem:

First, let me describe how I see a read-write lock. It has 3 states:
a) unlocked
b) locked by n readers
c) locked by 1 writer
There can either be 1 writer within the protected region or n>=0
readers within the region. When a writer wants to take the lock,
calling down_write(), it has to wait until the read count is 0. When a
reader wants to take the lock, calling down_read(), he has only to wait
until the the writer is done - there is no need to wait for the other
readers.

Now in a real-time system down_X() ought to have a deterministic
blocking time. It should be easy to make down_read() deterministic: If
there is a writer let it inherit the calling readers priority. 
However, down_write() is hard to make deterministic. Even if we assume
that the lock not only keeps track of the number of readers but keeps a
list of all the reader threads within the region it can traverse the list
and boost the priority of all those threads. If there is n readers when
down_write() is called the blocking time would be
 O(ceil(n/#cpus))
time - which is unbounded as n is not known!

Having a rw-lock with deterministic down_read() but non-deterministic
down_write() would be very usefull in a lot of cases. The characteritic is
that the data structure being protected is relative static, is going
to be used by a lot of RT readers and the updates doesn't have to be done
with any real-time requirements.
However, there is no way to know in general which locks in the kernel can
be allowed to work like that and which can't. A good compromise would be
limit the number of readers in a lock by the number of cpu's on the
system. That would make the system scale over several CPUs without hitting
unneeded congestions on read-locks and still have a determnistic
down_write(). 

down_write() shall then do the following: Boost the priority of all the
active readers to the priority of the caller. This will in turn distribute
the readers over the cpu's of the system assuming no higher priority RT
tasks are running. All the reader tasks will then run to up_read() in
time O(1) as they can all run in parellel - assuming there is no ugly
nested locking ofcourse!
down_read() should first check if there is a writer. If there is
boost it and wait. If there isn't but there isn't room for another reader
boost one of the readers such it will run to up_read().

An extra bonus of not having the number of readers bounded: The various
structures needed for making the list of readers can be allocated once.
There is no need to call kmalloc() from within down_read() to get a list
element for the lock's list of readers.

I don't know wether I have time for coding this soon. Under all
circumstances I do not have a SMP system so I can't really test it if I
get time to code it :-(

Esben



On Tue, 14 Dec 2004, Ingo Molnar wrote:

> 
> * Rui Nuno Capela <rncbc@rncbc.org> wrote:
> 
> > Isn't this tightly related to mkinitrd sometimes hanging while on
> > mount -o loop, that I've been reporting a couple of times before? It
> > used to hang on any other time I do a new kernel install, but latetly
> > it seems to be OK (RT-V0.9.32-19 and -20).
> 
> yeah, i've added Thomas Gleixner's earlier semaphore->completion
> conversion to the loop device, to -19 or -18.
> 
> 	Ingo
> -
> 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: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Steven Rostedt]

On Mon, 2004-12-27 at 15:35 +0100, Esben Nielsen wrote:
> I haven't seen much traffic on real-time preemption lately. Is it due
> to Christmas or lost interest?
> 

I think they are on vacation :-)

> I noticed that you changed rw-locks to behave quite diferently under
> real-time preemption: They basicly works like normal locks now. I.e. there
> can only be one reader task within each region. This can can however lock
> the region recursively. I wanted to start looking at fixing that because
> it ought to hurt scalability quite a bit - and even on UP create a few
> unneeded task-switchs. However, the more I think about it the bigger the 
> problem:
> 
> First, let me describe how I see a read-write lock. It has 3 states:
> a) unlocked
> b) locked by n readers
> c) locked by 1 writer
> There can either be 1 writer within the protected region or n>=0
> readers within the region. When a writer wants to take the lock,
> calling down_write(), it has to wait until the read count is 0. When a
> reader wants to take the lock, calling down_read(), he has only to wait
> until the the writer is done - there is no need to wait for the other
> readers.
> 
> Now in a real-time system down_X() ought to have a deterministic
> blocking time. It should be easy to make down_read() deterministic: If
> there is a writer let it inherit the calling readers priority. 
> However, down_write() is hard to make deterministic. Even if we assume
> that the lock not only keeps track of the number of readers but keeps a
> list of all the reader threads within the region it can traverse the list
> and boost the priority of all those threads. If there is n readers when
> down_write() is called the blocking time would be
>  O(ceil(n/#cpus))
> time - which is unbounded as n is not known!
> 
> Having a rw-lock with deterministic down_read() but non-deterministic
> down_write() would be very usefull in a lot of cases. The characteritic is
> that the data structure being protected is relative static, is going
> to be used by a lot of RT readers and the updates doesn't have to be done
> with any real-time requirements.
> However, there is no way to know in general which locks in the kernel can
> be allowed to work like that and which can't. A good compromise would be
> limit the number of readers in a lock by the number of cpu's on the
> system. That would make the system scale over several CPUs without hitting
> unneeded congestions on read-locks and still have a determnistic
> down_write(). 
> 

Why just limit to the number of CPUs, but make a configurable limit. I
would say the default may be 2*CPUs.  Reason being is that once you
limit the number of readers, you just bound the down_write. Even if
number of readers allowed is 100, the down_write is now bound to
O(ceil(n/#cpus)) as you said, but now n is known. Make a
CONFIG_ALLOWED_READERS or something to that affect, and it would be easy
to see what is a good optimal configuration (assuming you have the
proper tests).

> down_write() shall then do the following: Boost the priority of all the
> active readers to the priority of the caller. This will in turn distribute
> the readers over the cpu's of the system assuming no higher priority RT
> tasks are running. All the reader tasks will then run to up_read() in
> time O(1) as they can all run in parellel - assuming there is no ugly
> nested locking ofcourse!
> down_read() should first check if there is a writer. If there is
> boost it and wait. If there isn't but there isn't room for another reader
> boost one of the readers such it will run to up_read().
> 
> An extra bonus of not having the number of readers bounded: The various
> structures needed for making the list of readers can be allocated once.
> There is no need to call kmalloc() from within down_read() to get a list
> element for the lock's list of readers.
> 
> I don't know wether I have time for coding this soon. Under all
> circumstances I do not have a SMP system so I can't really test it if I
> get time to code it :-(
> 

I have two SMP machines that I can test on, unfortunately, they both
have NVIDIA cards, so I cant use them with X, unless I go back to the
default driver. Which I would do, but I really like the 3d graphics ;-)


-- Steve

> Esben
> 
> 
> 
> On Tue, 14 Dec 2004, Ingo Molnar wrote:
> 
> > 
> > * Rui Nuno Capela <rncbc@rncbc.org> wrote:
> > 
> > > Isn't this tightly related to mkinitrd sometimes hanging while on
> > > mount -o loop, that I've been reporting a couple of times before? It
> > > used to hang on any other time I do a new kernel install, but latetly
> > > it seems to be OK (RT-V0.9.32-19 and -20).
> > 
> > yeah, i've added Thomas Gleixner's earlier semaphore->completion
> > conversion to the loop device, to -19 or -18.
> > 
> > 	Ingo
> > -
> > 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/
> > 
> 
> -
> 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/
-- 
Steven Rostedt
Senior Engineer
Kihon Technologies

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Esben Nielsen]

On Mon, 27 Dec 2004, Steven Rostedt wrote:

> On Mon, 2004-12-27 at 15:35 +0100, Esben Nielsen wrote:
> > I haven't seen much traffic on real-time preemption lately. Is it due
> > to Christmas or lost interest?
> > 
> 
> I think they are on vacation :-)
>
Oh, I thought I would have fun with some kernel programming in my
vacation! :-)
 
> > [...]
> 
> Why just limit to the number of CPUs, but make a configurable limit. I
> would say the default may be 2*CPUs.  Reason being is that once you
> limit the number of readers, you just bound the down_write. Even if
> number of readers allowed is 100, the down_write is now bound to
> O(ceil(n/#cpus)) as you said, but now n is known. Make a
> CONFIG_ALLOWED_READERS or something to that affect, and it would be easy
> to see what is a good optimal configuration (assuming you have the
> proper tests).
> 
I agree with you that it ought to be configureable. But if you set it to
something like 100 it is _not_ deterministic in practise. I.e. during your
tests you have a really hard time making 100 readers at the critical
point. Most likely you only have a handfull. Then when you deploy the
system where you might have a webserver presenting data read under a
rw-lock is overloaded spawns 100 worker tasks. Bang! Your RT application
doesn't run!
It doesn't help you to have something bounded if the bound is insanely
high such you never reach it in tests. And if you try to calculate the
worst case scenarious for such a system you would find it doesn't
schedule. I.e. you have to buy a bigger CPU or do some other drastic
thing!

A limit like 1 reader per CPU on the other hand behaves like a
normal mutex priority inheritance wrt. determinism. And it scales like the
stock Linux rw-lock which in practise is also limited to 1 task per CPU as
preemption is switched off :-)

> [...] 
> I have two SMP machines that I can test on, unfortunately, they both
> have NVIDIA cards, so I cant use them with X, unless I go back to the
> default driver. Which I would do, but I really like the 3d graphics ;-)
> 

Well, these kind of things isn't something you want to combine with 3d
graphics right away anyway!
I have even had problems with crashing on 2.4.xx with a NVidia and
hyperthreading on a machine I helped install :-( 
I am afraid NVidia cards and preempt realtime is far in the future :-(

> 
> -- Steve
> 

Esben

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Steven Rostedt]

On Mon, 2004-12-27 at 17:23 +0100, Esben Nielsen wrote:


> > > [...]
> > 
> > Why just limit to the number of CPUs, but make a configurable limit. I
> > would say the default may be 2*CPUs.  Reason being is that once you
> > limit the number of readers, you just bound the down_write. Even if
> > number of readers allowed is 100, the down_write is now bound to
> > O(ceil(n/#cpus)) as you said, but now n is known. Make a
> > CONFIG_ALLOWED_READERS or something to that affect, and it would be easy
> > to see what is a good optimal configuration (assuming you have the
> > proper tests).
> > 
> I agree with you that it ought to be configureable. But if you set it to
> something like 100 it is _not_ deterministic in practise. I.e. during your
> tests you have a really hard time making 100 readers at the critical
> point. Most likely you only have a handfull. Then when you deploy the
> system where you might have a webserver presenting data read under a
> rw-lock is overloaded spawns 100 worker tasks. Bang! Your RT application
> doesn't run!
> It doesn't help you to have something bounded if the bound is insanely
> high such you never reach it in tests. And if you try to calculate the
> worst case scenarious for such a system you would find it doesn't
> schedule. I.e. you have to buy a bigger CPU or do some other drastic
> thing!
> 

I wasn't saying that 100 was a GOOD number, but that was just an
example. I'm one of those that don't like the program, application,
kernel, to limit you on how you want to shoot yourself in the foot. But
always have the default set to something that prevents the idiot from
doing something too idiotic.  

> A limit like 1 reader per CPU on the other hand behaves like a
> normal mutex priority inheritance wrt. determinism. And it scales like the
> stock Linux rw-lock which in practise is also limited to 1 task per CPU as
> preemption is switched off :-)
> 

Do you think 2/cpu is too high? I'd figure that reads usually happen way
more than writes, and writes can usually last longer than reads, but
having the default to two, you can test your code, on a UP.

> > [...] 
> > I have two SMP machines that I can test on, unfortunately, they both
> > have NVIDIA cards, so I cant use them with X, unless I go back to the
> > default driver. Which I would do, but I really like the 3d graphics ;-)
> > 
> 
> Well, these kind of things isn't something you want to combine with 3d
> graphics right away anyway!
> I have even had problems with crashing on 2.4.xx with a NVidia and
> hyperthreading on a machine I helped install :-( 
> I am afraid NVidia cards and preempt realtime is far in the future :-(
> 

Actually, I've had some success with NVIDIA on all my kernels (except of
course the realtime ones). Unfortunately, there are the little crashes
here and there, but those usually happen with screen savers so I don't
lose data. I just come back to the machine and say WTF, I'm at a login
prompt! I am one of those that save everything within seconds of
modifying, and use subversion commits like crazy :-)

-- Steve

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Bill Huey]

On Mon, Dec 27, 2004 at 11:39:20AM -0500, Steven Rostedt wrote:
> Actually, I've had some success with NVIDIA on all my kernels (except of

Doesn't the NVidia driver use their own version of DRM/DRI ?
If so, then did you tell it to use the Linux kernel versions of that
driver ?

> course the realtime ones). Unfortunately, there are the little crashes
> here and there, but those usually happen with screen savers so I don't

I was just having a discussion about this last night with a friend
of mine and I'm going to pose this question to you and others.

Is a real-time enabled kernel still relevant for high performance
video even with GPUs being as fast as they are these days ?

The context that I'm working with is that I was told (been out of
gaming for a long time now) that GPus are so fast these days that
shortage of frame rate isn't a problem any more. An RTOS would be
able to deliver a data/instructions to the GPU under a much tighter
time period and could delivery better, more consistent frame rates.

Does this assertion still apply or not ? why ? (for either answer)

bill

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Valdis.Kletnieks]

[-- Attachment #1: Type: text/plain, Size: 1838 bytes --]

On Mon, 27 Dec 2004 13:06:14 PST, Bill Huey said:

> Is a real-time enabled kernel still relevant for high performance
> video even with GPUs being as fast as they are these days ?

More to the point - can a RT kernel help *last* year's model?  My
laptop only has a GeForce4 440Go (which is closer to a GeForce2 in
reality) and a 1.6Gz Pentium4.  So it isn't any problem at all
to even find xscreensaver GL-hacks that bring it to its knees.

Even the venerable 'glxgears' drops down to about 40FPS in an 800x600
window.  I'm sure the average game has a *lot* more polygons in it than
glxgears does.  xscreensaver's 'sierpinski3d' drops down to 18FPS when it
gets up to 16K polygons.

Linux has long been reknowned for its ability to Get Stuff Done on much older
and less capable hardware than the stuff from Redmond.  Got an old box that
crawled under W2K and Win/XP won't even install? Toss the current RedHat or
Suse on it, and it goes...

Would be *really* nice if we could find similar tricks on the graphics side. ;)

> The context that I'm working with is that I was told (been out of
> gaming for a long time now) that GPus are so fast these days that
> shortage of frame rate isn't a problem any more. An RTOS would be
> able to deliver a data/instructions to the GPU under a much tighter
> time period and could delivery better, more consistent frame rates.
> 
> Does this assertion still apply or not ? why ? (for either answer)

Shortage of frame rate is *always* a problem.  No matter how many
millions of polygons/sec you can push out the door, somebody will want
to do N+25% per second.  Ask yourself why SGI was *EVER* able to sell
a machine with more than one InfiniteReality graphics engine on it, and
then ask yourself what the people who were using 3 IR pipes 5-6 years
ago are looking to use for graphics *this* year.

[-- Attachment #2: Type: application/pgp-signature, Size: 226 bytes --]

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Lee Revell]

On Mon, 2004-12-27 at 13:06 -0800, Bill Huey wrote:
> I was just having a discussion about this last night with a friend
> of mine and I'm going to pose this question to you and others.
> 
> Is a real-time enabled kernel still relevant for high performance
> video even with GPUs being as fast as they are these days ?
>
> The context that I'm working with is that I was told (been out of
> gaming for a long time now) that GPus are so fast these days that
> shortage of frame rate isn't a problem any more. An RTOS would be
> able to deliver a data/instructions to the GPU under a much tighter
> time period and could delivery better, more consistent frame rates.
> 
> Does this assertion still apply or not ? why ? (for either answer)

Yes, an RTOS certainly helps.  Otherwise you cannot guarantee a minimum
frame rate - if a long running disk ISR fires then you are screwed,
because jsut as with low latency audio you have a SCHED_FIFO userspace
process that is feeding data to the GPU at a constant rate.  Its a worse
problem with audio because you absolutely cannot drop a frame or you
will hear it.  With video it's likely to be imperceptible.

Lee

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Andrew McGregor]

On 28/12/2004, at 10:06 AM, Bill Huey (hui) wrote:

> On Mon, Dec 27, 2004 at 11:39:20AM -0500, Steven Rostedt wrote:
>> Actually, I've had some success with NVIDIA on all my kernels (except 
>> of
>
> Doesn't the NVidia driver use their own version of DRM/DRI ?
> If so, then did you tell it to use the Linux kernel versions of that
> driver ?
>
>> course the realtime ones). Unfortunately, there are the little crashes
>> here and there, but those usually happen with screen savers so I don't
>
> I was just having a discussion about this last night with a friend
> of mine and I'm going to pose this question to you and others.
>
> Is a real-time enabled kernel still relevant for high performance
> video even with GPUs being as fast as they are these days ?

It is if you want to do any audio at the same time, as you usually do.

Andrew

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Lee Revell]

On Mon, 2004-12-27 at 17:23 +0100, Esben Nielsen wrote:
> I am afraid NVidia cards and preempt realtime is far in the future :-(

Not necessarily.  I am sure many of Nvidia's potential customers want to
do high end simulation and that requires an RT capable OS and good
graphics hardware.  If many people end up using RT preempt for high end
simulator applications, like several who have posted on this list, then
it seems like it would a good fit.

Lee

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Ingo Molnar]

* Esben Nielsen <simlo@phys.au.dk> wrote:

> I noticed that you changed rw-locks to behave quite diferently under
> real-time preemption: They basicly works like normal locks now. I.e.
> there can only be one reader task within each region. This can can
> however lock the region recursively. [...]

correct.

> [...] I wanted to start looking at fixing that because it ought to
> hurt scalability quite a bit - and even on UP create a few unneeded
> task-switchs. [...]

no, it's not a big scalability problem. rwlocks are really a mistake -
if you want scalability and spinlocks/semaphores are not enough then one
should either use per-CPU locks or lockless structures. rwlocks/rwsems
will very unlikely help much.

> However, the more I think about it the bigger the problem:

yes, that complexity to get it perform in a deterministic manner is why
i introduced this (major!) simplification of locking. It turns out that
most of the time the actual use of rwlocks matches this simplified
'owner-recursive exclusive lock' semantics, so we are lucky.

look at what kind of worst-case scenarios there may already be with
multiple spinlocks (blocker.c). With rwlocks that just gets insane.

	Ingo

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[William Lee Irwin III]

* Esben Nielsen <simlo@phys.au.dk> wrote:
>> [...] I wanted to start looking at fixing that because it ought to
>> hurt scalability quite a bit - and even on UP create a few unneeded
>> task-switchs. [...]

On Fri, Jan 28, 2005 at 08:38:56AM +0100, Ingo Molnar wrote:
> no, it's not a big scalability problem. rwlocks are really a mistake -
> if you want scalability and spinlocks/semaphores are not enough then one
> should either use per-CPU locks or lockless structures. rwlocks/rwsems
> will very unlikely help much.

I wouldn't be so sure about that. SGI is already implicitly relying on
the parallel holding of rwsems for the lockless pagefaulting, and
Oracle has been pushing on mapping->tree_lock becoming an rwlock for a
while, both for large performance gains.


* Esben Nielsen <simlo@phys.au.dk> wrote:
>> However, the more I think about it the bigger the problem:

On Fri, Jan 28, 2005 at 08:38:56AM +0100, Ingo Molnar wrote:
> yes, that complexity to get it perform in a deterministic manner is why
> i introduced this (major!) simplification of locking. It turns out that
> most of the time the actual use of rwlocks matches this simplified
> 'owner-recursive exclusive lock' semantics, so we are lucky.
> look at what kind of worst-case scenarios there may already be with
> multiple spinlocks (blocker.c). With rwlocks that just gets insane.

tasklist_lock is one large exception; it's meant for concurrency there,
and it even gets sufficient concurrency to starve the write side.

Try test_remap.c on mainline vs. -mm to get a microbenchmark-level
notion of the importance of mapping->tree_lock being an rwlock (IIRC
you were cc:'d in at least some of those threads).

net/ has numerous rwlocks, which appear to frequently be associated
with hashtables, and at least some have some relevance to performance.

Are you suggesting that lockless alternatives to mapping->tree_lock,
mm->mmap_sem, and tasklist_lock should be pursued now?


-- wli

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Ingo Molnar]

* William Lee Irwin III <wli@holomorphy.com> wrote:

> On Fri, Jan 28, 2005 at 08:38:56AM +0100, Ingo Molnar wrote:
> > no, it's not a big scalability problem. rwlocks are really a mistake -
> > if you want scalability and spinlocks/semaphores are not enough then one
> > should either use per-CPU locks or lockless structures. rwlocks/rwsems
> > will very unlikely help much.
> 
> I wouldn't be so sure about that. SGI is already implicitly relying on
> the parallel holding of rwsems for the lockless pagefaulting, and
> Oracle has been pushing on mapping->tree_lock becoming an rwlock for a
> while, both for large performance gains.

i dont really buy it. Any rwlock-type of locking causes global cacheline
bounces. It can make a positive scalability difference only if the
read-lock hold time is large, at which point RCU could likely have
significantly higher performance. There _may_ be an intermediate locking
pattern that is both long-held but has a higher mix of write-locking
where rwlocks/rwsems may have a performance advantage over RCU or
spinlocks.

Also this is about PREEMPT_RT, mainly aimed towards embedded systems,
and at most aimed towards small (dual-CPU) SMP systems, not the really
big systems.

But, the main argument wrt. PREEMPT_RT stands and is independent of any
scalability properties: rwlocks/rwsems have so bad deterministic
behavior that they are almost impossible to implement in a sane way.

	Ingo

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[William Lee Irwin III]

* William Lee Irwin III <wli@holomorphy.com> wrote:
>> I wouldn't be so sure about that. SGI is already implicitly relying on
>> the parallel holding of rwsems for the lockless pagefaulting, and
>> Oracle has been pushing on mapping->tree_lock becoming an rwlock for a
>> while, both for large performance gains.

On Fri, Jan 28, 2005 at 04:28:02PM +0100, Ingo Molnar wrote:
> i dont really buy it. Any rwlock-type of locking causes global cacheline
> bounces. It can make a positive scalability difference only if the
> read-lock hold time is large, at which point RCU could likely have
> significantly higher performance. There _may_ be an intermediate locking
> pattern that is both long-held but has a higher mix of write-locking
> where rwlocks/rwsems may have a performance advantage over RCU or
> spinlocks.

The performance relative to mutual exclusion is quantifiable and very
reproducible. These results have people using arguments similar to what
you made above baffled. Systems as small as 4 logical cpus feel these
effects strongly, and it appears to scale almost linearly with the
number of cpus. It may be worth consulting an x86 processor architect
or similar to get an idea of why the counterargument fails. I'm rather
interested in hearing why as well, as I believed the cacheline bounce
argument until presented with incontrovertible evidence to the contrary.

As far as performance relative to RCU goes, I suspect cases where
write-side latency is important will arise for these. Other lockless
methods are probably more appropriate, and are more likely to dominate
rwlocks as expected. For instance, a reimplementation of the radix
trees for lockless insertion and traversal (c.f. lockless pagetable
patches for examples of how that's carried out) is plausible, where RCU
memory overhead in struct page is not.


On Fri, Jan 28, 2005 at 04:28:02PM +0100, Ingo Molnar wrote:
> Also this is about PREEMPT_RT, mainly aimed towards embedded systems,
> and at most aimed towards small (dual-CPU) SMP systems, not the really
> big systems.
> But, the main argument wrt. PREEMPT_RT stands and is independent of any
> scalability properties: rwlocks/rwsems have so bad deterministic
> behavior that they are almost impossible to implement in a sane way.

I suppose if it's not headed toward mainline the counterexamples don't
really matter. I don't have much to say about the RT-related issues,
though I'm aware of priority inheritance's infeasibility for the
rwlock/rwsem case.


-- wli

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Ingo Molnar]

* William Lee Irwin III <wli@holomorphy.com> wrote:

> The performance relative to mutual exclusion is quantifiable and very
> reproducible. [...]

yes, i dont doubt the results - my point is that it's not proven that
the other, more read-friendly types of locking underperform rwlocks. 
Obviously spinlocks and rwlocks have the same cache-bounce properties,
so rwlocks can outperform spinlocks if the read path overhead is higher
than that of a bounce, and reads are dominant. But it's still a poor
form of scalability. In fact, when the read path is really expensive
(larger than say 10-20 usecs) an rwlock can produce the appearance of
linear scalability, when compared to spinlocks.

> As far as performance relative to RCU goes, I suspect cases where
> write-side latency is important will arise for these. Other lockless
> methods are probably more appropriate, and are more likely to dominate
> rwlocks as expected. For instance, a reimplementation of the radix
> trees for lockless insertion and traversal (c.f. lockless pagetable
> patches for examples of how that's carried out) is plausible, where
> RCU memory overhead in struct page is not.

yeah.

	Ingo

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Trond Myklebust]

fr den 28.01.2005 Klokka 08:38 (+0100) skreiv Ingo Molnar:

> no, it's not a big scalability problem. rwlocks are really a mistake -
> if you want scalability and spinlocks/semaphores are not enough then one
> should either use per-CPU locks or lockless structures. rwlocks/rwsems
> will very unlikely help much.

If you do have a highest interrupt case that causes all activity to
block, then rwsems may indeed fit the bill.

In the NFS client code we may use rwsems in order to protect stateful
operations against the (very infrequently used) server reboot recovery
code. The point is that when the server reboots, the server forces us to
block *all* requests that involve adding new state (e.g. opening an
NFSv4 file, or setting up a lock) while our client and others are
re-establishing their existing state on the server.

IOW: If you are planning on converting rwsems into a semaphore, you will
screw us over most royally, by converting the currently highly
infrequent scenario of a single task being able to access the server
into the common case.

Cheers,
  Trond
-- 
Trond Myklebust <trond.myklebust@fys.uio.no>

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Ingo Molnar]

* Trond Myklebust <trond.myklebust@fys.uio.no> wrote:

> If you do have a highest interrupt case that causes all activity to
> block, then rwsems may indeed fit the bill.
> 
> In the NFS client code we may use rwsems in order to protect stateful
> operations against the (very infrequently used) server reboot recovery
> code. The point is that when the server reboots, the server forces us
> to block *all* requests that involve adding new state (e.g. opening an
> NFSv4 file, or setting up a lock) while our client and others are
> re-establishing their existing state on the server.

it seems the most scalable solution for this would be a global flag plus
per-CPU spinlocks (or per-CPU mutexes) to make this totally scalable and
still support the requirements of this rare event. An rwsem really
bounces around on SMP, and it seems very unnecessary in the case you
described.

possibly this could be formalised as an rwlock/rwlock implementation
that scales better. brlocks were such an attempt.

> IOW: If you are planning on converting rwsems into a semaphore, you
> will screw us over most royally, by converting the currently highly
> infrequent scenario of a single task being able to access the server
> into the common case.

nono, i have no such plans.

	Ingo

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Bill Huey]

On Fri, Jan 28, 2005 at 08:45:46PM +0100, Ingo Molnar wrote:
> * Trond Myklebust <trond.myklebust@fys.uio.no> wrote:
> > If you do have a highest interrupt case that causes all activity to
> > block, then rwsems may indeed fit the bill.
> > 
> > In the NFS client code we may use rwsems in order to protect stateful
> > operations against the (very infrequently used) server reboot recovery
> > code. The point is that when the server reboots, the server forces us
> > to block *all* requests that involve adding new state (e.g. opening an
> > NFSv4 file, or setting up a lock) while our client and others are
> > re-establishing their existing state on the server.
> 
> it seems the most scalable solution for this would be a global flag plus
> per-CPU spinlocks (or per-CPU mutexes) to make this totally scalable and
> still support the requirements of this rare event. An rwsem really
> bounces around on SMP, and it seems very unnecessary in the case you
> described.
> 
> possibly this could be formalised as an rwlock/rwlock implementation
> that scales better. brlocks were such an attempt.

>From how I understand it, you'll have to have a global structure to
denote an exclusive operation and then take some additional cpumask_t
representing the spinlocks set and use it to iterate over when doing a
PI chain operation.

Locking of each individual parametric typed spinlock might require
a raw_spinlock manipulate lists structures, which, added up, is rather
heavy weight.

No only that, you'd have to introduce a notion of it being counted
since it could also be aquired/preempted  by another higher priority
thread on that same procesor.  Not having this semantic would make the
thread in that specific circumstance effectively non-preemptable (PI
scheduler indeterminancy), where the mulipule readers portion of a
real read/write (shared-exclusve) lock would have permitted this.

	http://people.lynuxworks.com/~bhuey/rt-share-exclusive-lock/rtsem.tgz.1208

Is our attempt at getting real shared-exclusive lock semantics in a
blocking lock and may still be incomplete and buggy. Igor is still
working on this and this is the latest that I have of his work. Getting
comments on this approach would be a good thing as I/we (me/Igor)
believed from the start that this approach is correct.

Assuming that this is possible with the current approach, optimizing
it to avoid CPU ping-ponging is an important next step

bill

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Lee Revell]

On Fri, 2005-01-28 at 11:18 -0800, Trond Myklebust wrote:
> In the NFS client code we may use rwsems in order to protect stateful
> operations against the (very infrequently used) server reboot recovery
> code. The point is that when the server reboots, the server forces us to
> block *all* requests that involve adding new state (e.g. opening an
> NFSv4 file, or setting up a lock) while our client and others are
> re-establishing their existing state on the server.

Hmm, when I was an ISP sysadmin I used to use this all the time.  NFS
mounts from the BSD/OS clients would start to act up under heavy web
server load and the cleanest way to get them to recover was to simulate
a reboot on the NetApp.  Of course Linux clients were unaffected, they
were just along for the ride ;-)

Lee

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Esben Nielsen]

On Fri, 28 Jan 2005, Ingo Molnar wrote:

> 
> * Esben Nielsen <simlo@phys.au.dk> wrote:
> 
> > I noticed that you changed rw-locks to behave quite diferently under
> > real-time preemption: They basicly works like normal locks now. I.e.
> > there can only be one reader task within each region. This can can
> > however lock the region recursively. [...]
> 
> correct.
> 
> > [...] I wanted to start looking at fixing that because it ought to
> > hurt scalability quite a bit - and even on UP create a few unneeded
> > task-switchs. [...]
> 
> no, it's not a big scalability problem. rwlocks are really a mistake -
> if you want scalability and spinlocks/semaphores are not enough then one
> should either use per-CPU locks or lockless structures. rwlocks/rwsems
> will very unlikely help much.
>
I agree that RCU ought to do the trick in a lot of cases. Unfortunately,
people haven't used RCU in a lot of code but an rwlock. I also like the
idea of rwlocks: Many readers or just one writer. I don't see the need to
take that away from people.  Here is an examble which even on a UP will
give problems without it:
You have a shared datastructure, rarely updated with many readers. A low
priority task is reading it. That is preempted a high priority task which
finds out it can't read it -> priority inheritance, task switch. The low
priority task finishes the job -> priority set back, task switch. If it
was done with a rwlock two task switchs would have been saved.

 
> > However, the more I think about it the bigger the problem:
> 
> yes, that complexity to get it perform in a deterministic manner is why
> i introduced this (major!) simplification of locking. It turns out that
> most of the time the actual use of rwlocks matches this simplified
> 'owner-recursive exclusive lock' semantics, so we are lucky.
> 
> look at what kind of worst-case scenarios there may already be with
> multiple spinlocks (blocker.c). With rwlocks that just gets insane.
> 
Yes it does. But one could make a compromise: The up_write() should _not_
be deterministic. In that case it would be very simple to implement.
up_read() could still be deterministic as it would only involve boosting
one writer in the rare case such exists. That kind of locking would be
very usefull in many real-time systems. Ofcourse, RCU can do the job as
well, but it puts a lot of contrains on the code. 

However, as Linux is a general OS there is no way to know wether a
specific lock needs to be determnistic wrt. writing or not as the actual
application is not known at the time the lock type is specified.

> 	Ingo
> 

Esben

Re: Real-time rw-locks (Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15)

[Kyle Moffett]

For anybody who wants a good executive summary of RCU, see these:
http://lse.sourceforge.net/locking/rcupdate.html
http://lse.sourceforge.net/locking/rcu/HOWTO/intro.html#WHATIS

On Jan 30, 2005, at 17:03, Esben Nielsen wrote:
> I agree that RCU ought to do the trick in a lot of cases. 
> Unfortunately,
> people haven't used RCU in a lot of code but an rwlock. I also like the
> idea of rwlocks: Many readers or just one writer.

Well, RCU is nice because as long as there are no processes attempting 
to
modify the data, the performance is as though there was no locking at 
all,
which is better than the cacheline-bouncing for rwlock read-acquires,
which must modify the rwlock data every time you acquire.  It's only 
when
you need to modify the data that readers or other writers must repeat
their calculations when they find out that the data's changed.  In the
case of a reader and a writer, the performance reduction is the same as 
a
cmpxchg and the reader redoing their calculations (if necessary).

> You have a shared datastructure, rarely updated with many readers. A 
> low
> priority task is reading it. That is preempted a high priority task 
> which
> finds out it can't read it -> priority inheritance, task switch. The 
> low
> priority task finishes the job -> priority set back, task switch. If it
> was done with a rwlock two task switchs would have been saved.

With RCU the high priority task (unlikely to be preempted) gets to run 
all
the way through with its calculation, and any low priority tasks are the
ones that will probably need to redo their calculations.

> Yes it does. But one could make a compromise: The up_write() should 
> _not_
> be deterministic. In that case it would be very simple to implement.
> up_read() could still be deterministic as it would only involve 
> boosting
> one writer in the rare case such exists. That kind of locking would be
> very usefull in many real-time systems. Ofcourse, RCU can do the job as
> well, but it puts a lot of contrains on the code.

Yeah, unfortunately it's harder to write good reliable RCU code than 
good
reliable rwlock code, because the semantics of RCU WRT memory access are
much more difficult, so more people write rwlock code that needs to be
cleaned up.  It's not like normal locking is easily comprehensible 
either.
:-\

Cheers,
Kyle Moffett

-----BEGIN GEEK CODE BLOCK-----
Version: 3.12
GCM/CS/IT/U d- s++: a18 C++++>$ UB/L/X/*++++(+)>$ P+++(++++)>$
L++++(+++) E W++(+) N+++(++) o? K? w--- O? M++ V? PS+() PE+(-) Y+
PGP+++ t+(+++) 5 X R? tv-(--) b++++(++) DI+ D+ G e->++++$ h!*()>++$ r  
!y?(-)
------END GEEK CODE BLOCK------

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Mark_H_Johnson]

> * Mark_H_Johnson@raytheon.com <Mark_H_Johnson@raytheon.com> wrote:
>
> > The maximum duration of the CPU loop (as measured by the application)
> > is in the range of 1.42 msec to 2.57 compared to the nominal 1.16 msec
> > duration for -20RT.  The equivalent numbers for -20PK are 1.28 to 1.93
> > msec. [...]
>
> so -20RT has resolved all the CPU-loop-max-delay issues of the -RT
> kernel regarding the RT-priority CPU loop and in essence adds only a
> small amount of delay (100 usecs?) to the nominal (==minimum possible)
> delay?
I believe so, or in other words a minor penalty to average latency impact
to get a reduction in maximum latency [though I am not sure I actually
measured such a reduction].

> i suspect the 100 usecs comparison is an effect of the cutoff value
> being a single value. Also, 100 usecs is so close to the DMA related
> delay which makes it hard to compare it - other than stating that -RT
> has higher CPU overhead.
I think we agree on this assessment. I don't think the threading overhead
is 100 usec but more likely 50 usec [at least on my hardware - see below].
That the extra 50 usec puts us over the 100 usec measure is unfortunate.

> are the ping times still considered anomalous? Could be a side-effect of
> the different flow of control between hardirq/softirq contexts. (There
> have been a (low but nonzero) number of assumptions about the flow in
> pieces of softirq code, and there could be more.)
Please note that to get the ping times I stated, I set the priority of
ksoftirqd/0 and /1 to 99 (along with the IRQ threads). Others won't be
so generous and get different results.

I believe the longer duration with -20RT is due to the threading overhead.
Look at the numbers for -20PK and -20RT, the minimums are
  -20PK 0.089 msec (or 089 usec)
  -20RT 0.134 msec (or 134 usec)
or a difference of about 50 usec. If the sequence of steps is something
like
  Network Interrupt -T-> Network IRQ -T-> ksoftirqd/0 -> ping reply
on -RT and
  Network Interrupt -> Network IRQ -> soft IRQ -> ping reply
on -PK, the difference measured is likely reasonable.

[where -T-> represents a new thread activation, and -> represents something
like a function call]

Again, the benefit of PREEMPT_RT (over PREEMPT_DESKTOP) should be reduced
maximum latencies with a modest (or very little) impact to overall
performance / throughput. We are certainly getting a lot closer on
reaching that goal.

--Mark H Johnson
  <mailto:Mark_H_Johnson@raytheon.com>

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Mark_H_Johnson]

A comparison of PREEMPT_RT (no tracing) to PREEMPT_DESKTOP
(no tracing) to help answer previous requests.

Comparison of .32-20RT and .32-20PK results
20RT has PREEMPT_RT (all tracing disabled)
20PK has PREEMPT_DESKTOP and no threaded IRQ's (all tracing disabled)
2.4 has lowlat + preempt patches applied

      within 100 usec
       CPU loop (%)   Elapsed Time (sec)    2.4
Test   RT     PK        RT      PK   |   CPU  Elapsed
X     99.87  99.75      65 *    59 * |  97.20   70
top   99.35  99.97      31 *    30 * |  97.48   29
neto  96.94  98.65     113 *   135 * |  96.23   36
neti  97.05  98.59     119 *   140 * |  95.86   41
diskw 94.36  91.69      30 *    70 * |  77.64   29
diskc 93.85  98.88      98 *   151 * |  84.12   77
diskr 99.39  99.92     133 *   210 * |  90.66   86
total                  589     795   |         368
 [higher is better]  [lower is better]
* wide variation in audio duration
+ long stretch of audio duration "too fast"

With the two versions of -20, they are quite similar in the
percentage of CPU loop duration within 100 usec of nominal.

Looking at ping response time:
  RT 0.134 / 0.208 / 1.502 / 0.075 msec
  PK 0.089 / 0.159 / 0.467 / 0.047 msec
for min / average / max / mdev values. You can see that
-20PK does much better than -20RT in this measure.

The maximum duration of the CPU loop (as measured by the
application) is in the range of 1.42 msec to 2.57 compared
to the nominal 1.16 msec duration for -20RT. The equivalent
numbers for -20PK are 1.28 to 1.93 msec. Its a little odd
that the big outlier for -20PK was during the X 11 stress
test. Its chart was one of the smoothest (less variation)
than the others.

I repeated the test without cpu_burn (non RT, nice) for the
20PK kernel as well.  For -20PK, all the elapsed times were
reduced [as I expected for both RT and PK] and with exception
of the network tests, were roughly the same as the 2.4 results.

-20RT
  with cpu_burn      65  31 113 119  30  98 133
  without cpu_burn   63  30 121 150  32  87  97
-20PK
  with cpu_burn      59  30 135 140  70 151 210
  without cpu_burn   62  30  94  60  27  89  93

I reran the 2.4 tests and the network tests ran in 39 and 37
seconds respectively. I guess this shows we have something odd
going on in the network stack under 2.6.

--Mark H Johnson
  <mailto:Mark_H_Johnson@raytheon.com>

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Ingo Molnar]

* Mark_H_Johnson@raytheon.com <Mark_H_Johnson@raytheon.com> wrote:

> The maximum duration of the CPU loop (as measured by the application)
> is in the range of 1.42 msec to 2.57 compared to the nominal 1.16 msec
> duration for -20RT.  The equivalent numbers for -20PK are 1.28 to 1.93
> msec. [...]

so -20RT has resolved all the CPU-loop-max-delay issues of the -RT
kernel regarding the RT-priority CPU loop and in essence adds only a
small amount of delay (100 usecs?) to the nominal (==minimum possible)
delay?

i suspect the 100 usecs comparison is an effect of the cutoff value
being a single value. Also, 100 usecs is so close to the DMA related
delay which makes it hard to compare it - other than stating that -RT
has higher CPU overhead.

are the ping times still considered anomalous? Could be a side-effect of
the different flow of control between hardirq/softirq contexts. (There
have been a (low but nonzero) number of assumptions about the flow in
pieces of softirq code, and there could be more.)

	Ingo

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Mark_H_Johnson]

A comparison of PREEMPT_RT (no tracing) to PREEMPT_DESKTOP
(with tracing) to help answer previous requests.

Comparison of .32-20RT and .32-18PK results
20RT has PREEMPT_RT (all tracing disabled)
18PK has PREEMPT_DESKTOP and no threaded IRQ's (tracing enabled)
2.4 has lowlat + preempt patches applied

      within 100 usec
       CPU loop (%)   Elapsed Time (sec)    2.4
Test   RT     PK        RT      PK   |   CPU  Elapsed
X     99.87 100.00&     65 *    64+  |  97.20   70
top   99.35 100.00&     31 *    31+  |  97.48   29
neto  96.94 100.00&    113 *   184+  |  96.23   36
neti  97.05 100.00&    119 *   170+  |  95.86   41
diskw 94.36  99.99      30 *    61+  |  77.64   29
diskc 93.85  99.34      98 *   310+  |  84.12   77
diskr 99.39  99.96     133 *   310+  |  90.66   86
total                  589    1130   |         368
 [higher is better]  [lower is better]
* wide variation in audio duration
+ long stretch of audio duration "too fast"
& 100% to digits shown, had a FEW samples > 100 usec.

The results for -20RT (without tracing) are much better than
-18RT (with tracing) but still not quite as good as -18PK
with respect to the 100 usec delays.

The overhead of threading the IRQ's (and rescheduling the
RT application making the measurements) is likely cause of
the difference in 100 usec latency measurements.

I believe the threading overhead is confirmed by the slightly
slower ping response measurements:
  RT 0.134 / 0.208 / 1.502 / 0.075 msec
  PK 0.102 / 0.164 / 0.708 / 0.044 msec
for min / average / max / mdev values. These are much
better than with -18RT (with tracing) as well. Apparently the
tracing overhead is pretty high in the task switching area.

The maximum duration of the CPU loop (as measured by the
application) is in the range of 1.42 msec to 2.57 compared
to the nominal 1.16 msec duration for -20RT.

The non RT starvation problem appears to be mitigated quite
a bit by removing the tracing. I did a follow up test without
cpu_burn (non RT, nice) and the elapsed times varied in an
odd pattern:

  with cpu_burn      65  31 113 119  30  98 133
  without cpu_burn   63  30 121 150  32  87  97

The disk numbers are getting much closer to the 2.4 values
so removal of cpu_burn definitely helps prevent starvation.
The larger network numbers are something I should probably
confirm on my 2.4 test system to see if something changed
on the network to skew the results.

I will be building a -20PK without tracing for a more complete
comparison.

--Mark H Johnson
  <mailto:Mark_H_Johnson@raytheon.com>

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Ingo Molnar]

* Mark_H_Johnson@raytheon.com <Mark_H_Johnson@raytheon.com> wrote:

> A comparison of PREEMPT_RT (no tracing) to PREEMPT_DESKTOP
> (with tracing) to help answer previous requests.
> 
> Comparison of .32-20RT and .32-18PK results
> 20RT has PREEMPT_RT (all tracing disabled)
> 18PK has PREEMPT_DESKTOP and no threaded IRQ's (tracing enabled)
> 2.4 has lowlat + preempt patches applied
> 
>       within 100 usec
>        CPU loop (%)   Elapsed Time (sec)    2.4
> Test   RT     PK        RT      PK   |   CPU  Elapsed
> X     99.87 100.00&     65 *    64+  |  97.20   70
> top   99.35 100.00&     31 *    31+  |  97.48   29
> neto  96.94 100.00&    113 *   184+  |  96.23   36
> neti  97.05 100.00&    119 *   170+  |  95.86   41

interesting - the PK kernel with tracing enabled performs better than
the PK kernel with tracing disabled? Sounds counter-intuitive.

	Ingo

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Mark_H_Johnson]

Here is my get_ltrace.sh script (at the end).

So I read the preempt_max_latency (to see if its changed) before
I copy the latency_trace output. I am not so sure that cat is
really doing an "atomic" read when some of the latency traces
are over 300 Kbytes in length.

Also note that some of the files were empty :-(. I don't think
I've seen that symptom before.

Note that the preempt_max_latency value DID match the last line of
the trace output in the example I described. It is just the header
that had some stale data in it.

  --Mark

--- get_ltrace.sh ---

#!/bin/sh

let MAX=`cat /proc/sys/kernel/preempt_max_latency`
let I=0 J=1
let MP=${1:-1000}
echo "Current Maximum is $MAX, limit will be $MP."
while (( I < 100 )) ; do
    sleep 1s
    let NOW=`cat /proc/sys/kernel/preempt_max_latency`
    if (( MAX != NOW )) ; then
        echo "New trace $I w/ $NOW usec latency."
        cat /proc/latency_trace > lt.`printf "%02d" $I`
#       sync ; sync
        let I++
        let MAX=NOW
    elif (( J++ >= 10 )) ; then
        if (( MAX != MP )) ; then
            echo "Resetting max latency from $MAX to $MP."
            echo $MP > /proc/sys/kernel/preempt_max_latency
            let MAX=$MP
        else
            echo "No new latency samples at `date`."
        fi
        let J=1
# else do nothing...
    fi
done

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Ingo Molnar]

* Mark_H_Johnson@raytheon.com <Mark_H_Johnson@raytheon.com> wrote:

> Here is my get_ltrace.sh script (at the end).
> 
> So I read the preempt_max_latency (to see if its changed) before I
> copy the latency_trace output. I am not so sure that cat is really
> doing an "atomic" read when some of the latency traces are over 300
> Kbytes in length.

reading preempt_max_latency ought to be fine to detect changes.

yes, even a 300 KB trace should be read atomically too, even if it takes
3 seconds to save, hence all the different layers of trace buffers. The
kernel does not update the output buffer until the 'cat' has finished.
(unless a parallel 'cat' interferes - all your scripts are serialized,
right?)

> Also note that some of the files were empty :-(. I don't think I've
> seen that symptom before.

hm, an empty file occurs if the saved output trace is empty. This should
only be the case shortly after resetting preempt_max_latency. (or after
bootup, until it's set for the first time.)

> Note that the preempt_max_latency value DID match the last line of the
> trace output in the example I described. It is just the header that
> had some stale data in it.

yeah. It's weird. Ahh .. reviewing the header-generation code again i
noticed a buglet, which could cause spuriously wrong latency values on
SMP systems. Does the patch below fix this particular symptom?

	Ingo

--- linux/kernel/latency.c.orig
+++ linux/kernel/latency.c
@@ -542,7 +542,7 @@ static void update_out_trace(void)
 	 * trace buffer.
 	 */
 	tmp_out = out_tr.traces + 0;
-	*tmp_out = max_tr.traces[0]; // TODO: dont copy the traces
+	*tmp_out = max_tr.traces[max_tr.cpu]; // TODO: dont copy the traces
 	out_tr.cpu = max_tr.cpu;
 	out_entry = tmp_out->trace + 0;
 

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Mark_H_Johnson]

>the only recent thing added was the global RT balancer, which is not
>active under PREEMPT_DESKTOP. Maybe this code somehow interferes with
>your workload? Could you try to disable it, ...

Real life will intervene before I can get the kernel built & tested
[have to pick up the kids...]. Will try this (w/o any tracing as well)
on Monday (and see if I can put RT in a good light...).

  --Mark

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Mark_H_Johnson]

The code does not quite match either pattern but is perhaps
more like your second example.

For reference, the cpu_delay loop looks like this...

  t1 = mygettime();
  for(u=0;u<(loops/1000);u++) {
    t0 = t1;
    if (do_a_trace) {
      gettimeofday(0, (struct timezone*)1);
    }
    for (v=0;v<1000;v++)
      k+=1;
    t1 = mygettime();
    if ((t1-t0)>max_delay){
      delay++;
      if (do_a_trace) {
        gettimeofday(0,0);
        do_a_trace = 0;
        printf("Trace triggered with %f second delay.\n",t1-t0);
      }
    }
  }

I was trying to avoid the extra "rdtsc" overhead (plus the
floating point calculations) so - yes, I could have cases
where the time I measure is not caught by the kernel tracer.

[do some tests...]
Now I'm 5 for 5 with the revised code. Odd that all the numbers
are within about 2 or 3 usec (application measured / kernel measured).
If it was as bad as I was measuring it, I would have expected
one or two to be really off.

  --Mark

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Ingo Molnar]

* Mark_H_Johnson@raytheon.com <Mark_H_Johnson@raytheon.com> wrote:

> The code does not quite match either pattern but is perhaps
> more like your second example.
> 
> For reference, the cpu_delay loop looks like this...
> 
>   t1 = mygettime();
>   for(u=0;u<(loops/1000);u++) {
>     t0 = t1;
>     if (do_a_trace) {
>       gettimeofday(0, (struct timezone*)1);
>     }
>     for (v=0;v<1000;v++)
>       k+=1;

If this is the code then on any modern CPU this is a delay on the order
of 2000 cycles - 2-3 usecs on your CPUs. The overhead of kernel entries
plus tracing is likely larger than this, so the window for the timing
race to occur ought to be pretty large.

this also means that the elapsed time of the CPU loop will be quite
variable, it will largely depend on the level and type of
tracing/debugging activated in the kernel. This could perhaps explain
the observed weirdnesses of the 'elapsed time' metric.

> [do some tests...]
> Now I'm 5 for 5 with the revised code. Odd that all the numbers
> are within about 2 or 3 usec (application measured / kernel measured).
> If it was as bad as I was measuring it, I would have expected
> one or two to be really off.

(5 for 5 means no missed latencies by the kernel tracer so far?)

	Ingo

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Mark_H_Johnson]

>* Mark_H_Johnson@raytheon.com <Mark_H_Johnson@raytheon.com> wrote:
>
>> [1] I still do not get traces where cpu_delay switches CPU's. I only
>> get trace output if it starts and ends on a single CPU. [...]
>
>lt001.18RT/lt.02 is such a trace. It starts on CPU#1:
>
> <unknown-3556  1...1    0µs : find_next_bit (user_trace_start)
>
>and ends on CPU#0:
>
> <unknown-3556  1...1  247µs : _raw_spin_lock_irqsave (user_trace_stop)
>
>the trace shows a typical migration of an RT task.

Hmm. Now I look at it more clearly like...
 # grep '^<unknown-3556' lt001.18RT/lt.02
I can see what you mean. Though this time it moved from one [22 usec]
to zero [189 usec] and back to one [238 usec] before it finally stopped
the trace at 248 usec. [the attempt to reschedule on CPU zero was
clearly ineffective]

This trace is also odd in that the duration of the trace in the header is
listed as 99 usec (and the application confirmed that) but the trace
ends at 248 usec.

Hmm. Now that I look at it, the duration in the header (99 usec) is the
duration of lt.01 (as reported by the script) but the total duration
of the trace (248 usec) is the duration from the script for lt.02.


--Mark H Johnson
  <mailto:Mark_H_Johnson@raytheon.com>

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Ingo Molnar]

* Mark_H_Johnson@Raytheon.com <Mark_H_Johnson@Raytheon.com> wrote:

> Hmm. Now that I look at it, the duration in the header (99 usec) is
> the duration of lt.01 (as reported by the script) but the total
> duration of the trace (248 usec) is the duration from the script for
> lt.02.

how do your collection scripts access /proc/latency_trace? The output is 
only atomic if the file is read as a whole, i.e.:

	cat /proc/latency_trace > wherever

or:

	cp /proc/latency wherever

but i guess you are doing this already ...

obviously tracing goes on while the scripts are saving the latency
trace, so the kernel goes to great lengths to try to guarantee
atomicity. There are 3 levels of tracing buffers:

	- 'current' trace buffers (per CPU)
	- 'max' trace buffer
	- 'output' trace buffer

the max trace is updated whenever a new max latency is detected. (not
stricly true: if one CPU is already saving a trace and this CPU detects
a new latency too then this CPU skips the trace, instead of spinning
waiting for the other CPU. This makes the tracing code more atomic, but
it opens up a window to 'lose' a latency - but statistically every
_type_ of latency should be saved sooner or later, since the 'dropping'
of traces is random, not systematic.)

the output trace is atomically filled in from the max trace, whenever
userspace accesses offset 0 of /proc/latency_trace. It will stay the
same until userspace finishes reading /proc/latency_trace (arrives to
the maximum offset of the file). Hence userspace can take all time it
wants to save a trace, it will stay the same. At least this is the
theory.

	Ingo

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Mark_H_Johnson]

Comparison of .32-18RT and .32-18PK results
RT has PREEMPT_RT,
PK has PREEMPT_DESKTOP and no threaded IRQ's.
2.4 has lowlat + preempt patches applied

      within 100 usec
       CPU loop (%)   Elapsed Time (sec)    2.4
Test   RT     PK        RT      PK   |   CPU  Elapsed
X     90.40 100.00&     73 *    64+  |  97.20   70
top   78.56 100.00&     39 *    31+  |  97.48   29
neto  92.82 100.00&    350 *   184+  |  96.23   36
neti  90.69 100.00&    350 *   170+  |  95.86   41
diskw 82.96  99.99     360 *    61+  |  77.64   29
diskc 91.41  99.34     350 *   310+  |  84.12   77
diskr 88.41  99.96     360 *   310+  |  90.66   86
total                 1881    1130   |         368
 [higher is better]  [lower is better]
* wide variation in audio duration
+ long stretch of audio duration "too fast"
& 100% to digits shown, had a FEW samples > 100 usec.

WOW! Look at the 100% values measured on -18PK. The performance
of 2.6 with PREEMPT_DESKTOP is far better than 2.4 preempt+lowlat
in every way except the non RT starvation problem. Something
fixed between -12 and -18 really made a big improvement.

It is still disturbing to see the worse results for -18RT
and I wish I knew what the cause was. Perhaps the traces I sent
earlier can provide a clue.

Other notes:

[1] -PK has many more latency traces > 250 usec [some MUCH longer]
than -RT. I ended up collecting more traces for -RT since I set
the limit to 100 usec, but only got about 8 > 250 usec traces
compared to 40 for -PK.

[2] Some of the traces in -PK are extremely long (up to 2 msec) and
I guess I'm glad I have an SMP system to run the RT application on
the other CPU. Here's an extract of one example:

reemption latency trace v1.1.4 on 2.6.10-rc2-mm3-V0.7.32-18PK
--------------------------------------------------------------------
 latency: 1698 us, #3137/3137, CPU#0 | (M:preempt VP:0, KP:1, SP:0 HP:0
#P:2)
    -----------------
    | task: kjournald-1203 (uid:0 nice:0 policy:0 rt_prio:0)
    -----------------

                 _------=> CPU#
                / _-----=> irqs-off
               | / _----=> need-resched
               || / _---=> hardirq/softirq
               ||| / _--=> preempt-depth
               |||| /
               |||||     delay
   cmd     pid ||||| time  |   caller
      \   /    |||||   \   |   /
<unknown-1203  0d..1    0µs < (54)
<unknown-1203  0...1    0µs : journal_remove_journal_head
(journal_commit_transaction)
<unknown-1203  0...1    1µs : __journal_remove_journal_head
(journal_remove_journal_head)
<unknown-1203  0...1    1µs : __brelse (__journal_remove_journal_head)
<unknown-1203  0...1    1µs : journal_free_journal_head
(journal_remove_journal_head)
<unknown-1203  0...1    1µs : kmem_cache_free (journal_free_journal_head)
<unknown-1203  0d..1    2µs : cache_flusharray (kmem_cache_free)
<unknown-1203  0d..1    2µs : _raw_spin_lock (cache_flusharray)
<unknown-1203  0d..2    2µs+: free_block (cache_flusharray)
<unknown-1203  0d..2    5µs : _raw_spin_unlock (cache_flusharray)
<unknown-1203  0d..1    5µs : memmove (cache_flusharray)
<unknown-1203  0d..1    5µs : memcpy (memmove)
<unknown-1203  0...1    6µs : inverted_lock (journal_commit_transaction)
<unknown-1203  0...1    6µs : __journal_unfile_buffer
(journal_commit_transaction)
<unknown-1203  0...1    7µs : journal_remove_journal_head
(journal_commit_transaction)
<unknown-1203  0...1    7µs : __journal_remove_journal_head
(journal_remove_journal_head)
<unknown-1203  0...1    8µs : __brelse (__journal_remove_journal_head)
<unknown-1203  0...1    8µs : journal_free_journal_head
(journal_remove_journal_head)
<unknown-1203  0...1    8µs : kmem_cache_free (journal_free_journal_head)
<unknown-1203  0...1    9µs : inverted_lock (journal_commit_transaction)
<unknown-1203  0...1    9µs : __journal_unfile_buffer
(journal_commit_transaction)
...
<unknown-1203  0...1  835µs : journal_remove_journal_head
(journal_commit_transaction)
<unknown-1203  0...1  835µs : __journal_remove_journal_head
(journal_remove_journal_head)
<unknown-1203  0...1  836µs : __brelse (__journal_remove_journal_head)
<unknown-1203  0...1  836µs : journal_free_journal_head
(journal_remove_journal_head)
<unknown-1203  0...1  837µs : kmem_cache_free (journal_free_journal_head)
<unknown-1203  0d..1  837µs : cache_flusharray (kmem_cache_free)
<unknown-1203  0d..1  837µs : _raw_spin_lock (cache_flusharray)
<unknown-1203  0d..2  838µs : free_block (cache_flusharray)
<unknown-1203  0d.h2  839µs : do_nmi (__mcount)
<unknown-1203  0d.h2  840µs : do_nmi (<08048340>)
<unknown-1203  0d.h2  840µs+: do_nmi (<00200282>)
<unknown-1203  0d..2  843µs : _raw_spin_unlock (cache_flusharray)
<unknown-1203  0d..1  844µs : memmove (cache_flusharray)
<unknown-1203  0d..1  844µs : memcpy (memmove)
<unknown-1203  0...1  844µs : inverted_lock (journal_commit_transaction)
...
<unknown-1203  0d.h2 1686µs : __mod_timer (ide_execute_command)
<unknown-1203  0d.h2 1686µs : _raw_spin_lock_irqsave (__mod_timer)
<unknown-1203  0d.h3 1687µs : _raw_spin_lock (__mod_timer)
<unknown-1203  0d.h4 1687µs : internal_add_timer (__mod_timer)
<unknown-1203  0d.h4 1687µs : _raw_spin_unlock (__mod_timer)
<unknown-1203  0d.h3 1688µs : _raw_spin_unlock_irqrestore (__mod_timer)
<unknown-1203  0d.h2 1688µs : ide_outbsync (ide_execute_command)
<unknown-1203  0d.h2 1689µs : __const_udelay (ide_execute_command)
<unknown-1203  0d.h2 1690µs : __delay (ide_execute_command)
<unknown-1203  0d.h2 1690µs : delay_tsc (__delay)
<unknown-1203  0d.h2 1691µs : _raw_spin_unlock_irqrestore
(ide_dma_exec_cmd)
<unknown-1203  0..h1 1691µs : ide_dma_start (__ide_do_rw_disk)
<unknown-1203  0..h1 1692µs : ide_inb (ide_dma_start)
<unknown-1203  0..h1 1692µs : ide_outb (ide_dma_start)
<unknown-1203  0..h1 1693µs : _raw_spin_lock_irq (ide_do_request)
<unknown-1203  0..h1 1693µs : _raw_spin_lock_irqsave (ide_do_request)
<unknown-1203  0d.h2 1694µs : _raw_spin_unlock_irqrestore (ide_intr)
<unknown-1203  0d.h1 1695µs : _raw_spin_lock (__do_IRQ)
<unknown-1203  0d.h2 1695µs : note_interrupt (__do_IRQ)
<unknown-1203  0d.h2 1696µs : end_edge_ioapic_irq (__do_IRQ)
<unknown-1203  0d.h2 1696µs : _raw_spin_unlock (__do_IRQ)
<unknown-1203  0d.h1 1696µs : irq_exit (do_IRQ)

[3] The charts are very smooth on -PK, very similar to those on
2.4 other than the "too fast" symptom for the audio duration.
[the white line is shifted down when compared to the nominal
duration yellow line]

[4] -PK also had two of the non RT starvation periods. Each was
almost 3 minutes long (should be a 5 second sleep). -RT had
none.

Will send the traces separately.
  --Mark

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Ingo Molnar]

* Mark_H_Johnson@raytheon.com <Mark_H_Johnson@raytheon.com> wrote:

> Comparison of .32-18RT and .32-18PK results
> RT has PREEMPT_RT,
> PK has PREEMPT_DESKTOP and no threaded IRQ's.
> 2.4 has lowlat + preempt patches applied
> 
>       within 100 usec
>        CPU loop (%)   Elapsed Time (sec)    2.4
> Test   RT     PK        RT      PK   |   CPU  Elapsed
> X     90.40 100.00&     73 *    64+  |  97.20   70
> top   78.56 100.00&     39 *    31+  |  97.48   29
> neto  92.82 100.00&    350 *   184+  |  96.23   36
> neti  90.69 100.00&    350 *   170+  |  95.86   41
> diskw 82.96  99.99     360 *    61+  |  77.64   29
> diskc 91.41  99.34     350 *   310+  |  84.12   77
> diskr 88.41  99.96     360 *   310+  |  90.66   86
> total                 1881    1130   |         368
>  [higher is better]  [lower is better]
> * wide variation in audio duration
> + long stretch of audio duration "too fast"
> & 100% to digits shown, had a FEW samples > 100 usec.
> 
> WOW! Look at the 100% values measured on -18PK. The performance of 2.6
> with PREEMPT_DESKTOP is far better than 2.4 preempt+lowlat in every
> way except the non RT starvation problem. Something fixed between -12
> and -18 really made a big improvement.

yep, i guess it's the two missed-preemption points i fixed in -16.

> It is still disturbing to see the worse results for -18RT and I wish I
> knew what the cause was. Perhaps the traces I sent earlier can provide
> a clue.

are you sure you got the order of the columns right? :-|

e.g. the lt004.18PK traces you sent show a number of huge latencies,
biggest one being 1949µs. The biggest one in lt001.18RT is 250 usecs,
and much of that i believe is due to debugging overhead. (It's not
apples to apples because i dont have the RT-under-stress traces yet.) 

something's really not kosher here.

> Other notes:
> 
> [1] -PK has many more latency traces > 250 usec [some MUCH longer]
> than -RT. I ended up collecting more traces for -RT since I set the
> limit to 100 usec, but only got about 8 > 250 usec traces compared to
> 40 for -PK.

this too is suspicious to me. How can then the PREEMPT_RT kernel end up
performing within 100 usecs in only 78.56% of the measurements - it's
ridiculously low! The tracer might have a bug, but such a selective bug?

the only recent thing added was the global RT balancer, which is not
active under PREEMPT_DESKTOP. Maybe this code somehow interferes with
your workload? Could you try to disable it, by changing kernel/sched.c's
#ifdefs from:

 #if defined(CONFIG_PREEMPT_RT) && defined(CONFIG_SMP)

to:

 #if 0

(there are ~5 such places in sched.c)

	Ingo

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Mark_H_Johnson]

This time, initial test results on -18PK (PREEMPT_DESKTOP, no IRQ
threading).

Again, results running cpu_delay and collecting user triggered traces.

[1] Similar symptoms where I do not get traces that span CPU's plus
the missing trace symptom.

# ./cpu_delay 0.000100
Delay limit set to 0.00010000 seconds
calibrating loop ....
time diff= 0.503365 or 397326229 loops/sec.
Trace activated with 0.000100 second delay.
Trace triggered with 0.000321 second delay. [not recorded]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000136 second delay. [not recorded]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000139 second delay. [00]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000130 second delay. [not recorded]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000240 second delay. [01]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000104 second delay. [02]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000130 second delay. [03]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000109 second delay. [04]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000109 second delay. [not recorded]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000155 second delay. [not recorded]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000100 second delay. [05]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000105 second delay. [not recorded]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000128 second delay. [06]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000123 second delay. [07]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000100 second delay. [08]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000113 second delay. [not recorded]
Trace activated with 0.000100 second delay.
Trace triggered with 0.000136 second delay. [09]

# chrt -f 1 ./get_ltrace.sh 50
Current Maximum is 4965280, limit will be 50.
Resetting max latency from 4965280 to 50.
No new latency samples at Fri Dec 10 13:42:31 CST 2004.
No new latency samples at Fri Dec 10 13:42:41 CST 2004.
No new latency samples at Fri Dec 10 13:42:51 CST 2004.
No new latency samples at Fri Dec 10 13:43:01 CST 2004.
New trace 0 w/ 139 usec latency.
Resetting max latency from 139 to 50.
No new latency samples at Fri Dec 10 13:43:23 CST 2004.
New trace 1 w/ 241 usec latency.
Resetting max latency from 241 to 50.
No new latency samples at Fri Dec 10 13:43:44 CST 2004.
New trace 2 w/ 103 usec latency.
Resetting max latency from 103 to 50.
New trace 3 w/ 130 usec latency.
Resetting max latency from 130 to 50.
No new latency samples at Fri Dec 10 13:44:17 CST 2004.
No new latency samples at Fri Dec 10 13:44:27 CST 2004.
No new latency samples at Fri Dec 10 13:44:37 CST 2004.
New trace 4 w/ 109 usec latency.
Resetting max latency from 109 to 50.
No new latency samples at Fri Dec 10 13:44:58 CST 2004.
New trace 5 w/ 100 usec latency.
Resetting max latency from 100 to 50.
New trace 6 w/ 128 usec latency.
Resetting max latency from 128 to 50.
New trace 7 w/ 123 usec latency.
Resetting max latency from 123 to 50.
New trace 8 w/ 100 usec latency.
Resetting max latency from 100 to 50.
No new latency samples at Fri Dec 10 13:45:54 CST 2004.
New trace 9 w/ 135 usec latency.
Resetting max latency from 135 to 50.

I don't see a significant difference in failures to record when compared
with -18RT (7 vs. 8).

[2] I get no ksoftirqd activity (as expected).

[3] Long sequences of one CPU only was seen again. Though in looking
at these traces I find several incomplete ones like this:

preemption latency trace v1.1.4 on 2.6.10-rc2-mm3-V0.7.32-18PK
--------------------------------------------------------------------
 latency: 139 us, #55/55, CPU#1 | (M:preempt VP:0, KP:1, SP:0 HP:0 #P:2)
    -----------------
    | task: cpu_delay-3517 (uid:0 nice:0 policy:1 rt_prio:30)
    -----------------
 => started at: <00000000>
 => ended at:   <00000000>

                 _------=> CPU#
                / _-----=> irqs-off
               | / _----=> need-resched
               || / _---=> hardirq/softirq
               ||| / _--=> preempt-depth
               |||| /
               |||||     delay
   cmd     pid ||||| time  |   caller
      \   /    |||||   \   |   /
<unknown-0     0d.h1    0µs : do_nmi (default_idle)
<unknown-0     0d.h1    0µs : do_nmi (_raw_spin_lock_irqsave)
<unknown-3517  1d.H2    0µs : do_nmi (default_idle)
<unknown-0     0d.h1    0µs : do_nmi (<00200246>)
<unknown-3517  1d.H2    0µs+: do_nmi ((514))
<unknown-0     0...1    3µs : default_idle (cpu_idle)
<unknown-3517  1d.H2    3µs : do_IRQ (c013a0cc 0 0)
<unknown-3517  1d.H2    3µs : _raw_spin_lock (__do_IRQ)
<unknown-3517  1d.H3    4µs : ack_edge_ioapic_irq (__do_IRQ)
<unknown-3517  1d.H3    4µs : redirect_hardirq (__do_IRQ)
<unknown-3517  1d.H3    5µs : _raw_spin_unlock (__do_IRQ)
<unknown-3517  1d.H2    5µs : handle_IRQ_event (__do_IRQ)
<unknown-3517  1d.H2    5µs : timer_interrupt (handle_IRQ_event)
<unknown-3517  1d.H2    6µs : _raw_spin_lock (timer_interrupt)
<unknown-3517  1d.H3    6µs : mark_offset_tsc (timer_interrupt)
<unknown-3517  1d.H3    7µs : _raw_spin_lock (mark_offset_tsc)
<unknown-3517  1d.H4    7µs+: _raw_spin_lock_irqsave (mark_offset_tsc)
<unknown-3517  1d.H5   13µs : _raw_spin_unlock_irqrestore (mark_offset_tsc)
<unknown-3517  1d.H4   14µs : _raw_spin_unlock (mark_offset_tsc)
<unknown-3517  1d.H3   14µs+: _raw_spin_lock_irqsave (timer_interrupt)
<unknown-3517  1d.H4   18µs : _raw_spin_unlock_irqrestore (timer_interrupt)
<unknown-3517  1d.H3   18µs : do_timer (timer_interrupt)
<unknown-3517  1d.H3   19µs : _raw_spin_unlock (timer_interrupt)
<unknown-3517  1d.H2   19µs : _raw_spin_lock (__do_IRQ)
<unknown-3517  1d.H3   20µs : note_interrupt (__do_IRQ)
<unknown-3517  1d.H3   20µs : end_edge_ioapic_irq (__do_IRQ)
<unknown-3517  1d.H3   21µs : _raw_spin_unlock (__do_IRQ)
<unknown-3517  1d.H2   21µs : irq_exit (do_IRQ)
<unknown-3517  1d.s2   21µs < (0)
<unknown-3517  1..s1   22µs : mod_timer (rt_check_expire)
<unknown-3517  1..s1   23µs : __mod_timer (rt_check_expire)
<unknown-3517  1..s1   23µs : _raw_spin_lock_irqsave (__mod_timer)
<unknown-3517  1d.s2   24µs : _raw_spin_lock (__mod_timer)
<unknown-3517  1d.s3   24µs : internal_add_timer (__mod_timer)
<unknown-3517  1d.s3   25µs : _raw_spin_unlock (__mod_timer)
<unknown-3517  1d.s2   25µs : _raw_spin_unlock_irqrestore (__mod_timer)
<unknown-3517  1..s1   26µs : cond_resched_all (run_timer_softirq)
<unknown-3517  1..s1   26µs : cond_resched_softirq (run_timer_softirq)
<unknown-3517  1..s1   26µs : _raw_spin_lock_irq (run_timer_softirq)
<unknown-3517  1..s1   27µs : _raw_spin_lock_irqsave (run_timer_softirq)
<unknown-3517  1d.s2   28µs : _raw_spin_unlock_irq (run_timer_softirq)
<unknown-3517  1..s1   29µs : __wake_up (run_timer_softirq)
<unknown-3517  1..s1   29µs : _raw_spin_lock_irqsave (__wake_up)
<unknown-3517  1d.s2   29µs : __wake_up_common (__wake_up)
<unknown-3517  1d.s2   30µs : _raw_spin_unlock_irqrestore
(run_timer_softirq)
<unknown-3517  1..s1   30µs : cond_resched_all (___do_softirq)
<unknown-3517  1..s1   30µs : cond_resched_softirq (___do_softirq)
<unknown-3517  1d...   31µs < (0)
<unknown-3517  1d...   32µs+< (0)
<unknown-3517  1....   35µs > sys_gettimeofday (00000000 00000000 0000007b)
<unknown-3517  1....   35µs : sys_gettimeofday (sysenter_past_esp)
<unknown-3517  1....   35µs : user_trace_stop (sys_gettimeofday)
<unknown-3517  1...1   36µs : user_trace_stop (sys_gettimeofday)
<unknown-3517  1...1   36µs : _raw_spin_lock_irqsave (user_trace_stop)
<unknown-3517  1d..2   37µs : _raw_spin_unlock_irqrestore (user_trace_stop)

I assume that since it does not start with user_trace_start (or something
like that) that the missing portion is the first portion.

[4] Not sure if I can make the same comment on -18PK as I did for -18RT
on changing CPU's [since I understand we do not have the opportunity to
do so unless the IRQ's are threaded].

[5] The trace output cosmetic problems are on PREEMPT_DESKTOP as well.

Traces to come shortly in a separate message.
  --Mark

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-6

[Mark_H_Johnson]

>on SMP, latencytest + all IRQ threads (and ksoftirqd) at prio 99 +
>PREEMPT_RT is not comparable to PREEMPT_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.

>The -RT kernel will 'split' hardirq and softirq workloads and migrate
>them to different CPUs - giving them a higher total throughput. Also, on
>PREEMPT_DESKTOP the 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...
>> 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.

>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).

>It's not clear-cut which one 'wins' though: because
>even this inverse scenario will have benefits in the -RT case: due to
>SCHED_OTHER workloads 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.

>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 to SCHED_OTHER tasks - 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)
>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]
>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:Mark_H_Johnson@raytheon.com>

Re: [patch] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-6

[Ingo Molnar]

* Mark_H_Johnson@raytheon.com <Mark_H_Johnson@raytheon.com> 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...
> >> 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.

> 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.

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).

> > 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.

> 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.

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.

>  [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)

>  [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.)

> 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.)

> 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.

> 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] Real-Time Preemption, -RT-2.6.10-rc2-mm3-V0.7.32-15

[Ingo Molnar]

* Ingo Molnar <mingo@elte.hu> wrote:

> 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

[Gene Heskett]

On Friday 10 December 2004 05:53, Ingo Molnar wrote:
>* Ingo Molnar <mingo@elte.hu> wrote:
>> 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.

>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
>-
>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/

-- 
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

[Gene Heskett]

On Friday 10 December 2004 09:59, Gene Heskett wrote:
>On Friday 10 December 2004 05:53, Ingo Molnar wrote:
>>* Ingo Molnar <mingo@elte.hu> wrote:
>>> 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.

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..

>
>>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
>>-
>>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/

-- 
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

[Lee Revell]

On Fri, 2004-12-10 at 11:53 +0100, Ingo Molnar wrote:
> The -32-15 kernel can be downloaded from the
> usual place:
> 
>  http://redhat.com/~mingo/realtime-preempt/

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 here
include/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