Hi Ingo et al.
(Sorry on the previous post, touched the wrong button :)
I'm sending (sent) some XRUN latencies captured just a minute ago.
xruntrace1.0.tar.gz
- scripts used for xrun trace capture automation
xruntrace1-2.6.10-rc2-mm3-RT-V0.7.31-7.tar.gz
- actual xrun traces captured while running jackd on RT-V0.7.31-7
config-2.6.10-rc2-mm3-RT-V0.7.31-7.gz
- kernel configuration as of my laptop, taken from /proc/config.gz
Cheers.
--
rncbc aka Rui Nuno Capela
[email protected]
* Rui Nuno Capela <[email protected]> wrote:
> config-2.6.10-rc2-mm3-RT-V0.7.31-7.gz
> - kernel configuration as of my laptop, taken from /proc/config.gz
Here are some .config suggestion to reduce tracing costs. Here's the
relevant portion of your .config:
CONFIG_DEBUG_KERNEL=y
CONFIG_MAGIC_SYSRQ=y
# CONFIG_SCHEDSTATS is not set
# CONFIG_DEBUG_SLAB is not set
CONFIG_DEBUG_PREEMPT=y
CONFIG_WAKEUP_TIMING=y
CONFIG_PREEMPT_TRACE=y
CONFIG_CRITICAL_PREEMPT_TIMING=y
CONFIG_CRITICAL_IRQSOFF_TIMING=y
CONFIG_CRITICAL_TIMING=y
CONFIG_LATENCY_TIMING=y
CONFIG_LATENCY_TRACE=y
CONFIG_MCOUNT=y
CONFIG_RT_DEADLOCK_DETECT=y
# CONFIG_DEBUG_KOBJECT is not set
CONFIG_DEBUG_BUGVERBOSE=y
# CONFIG_DEBUG_INFO is not set
CONFIG_FRAME_POINTER=y
CONFIG_EARLY_PRINTK=y
CONFIG_DEBUG_STACKOVERFLOW=y
i'd suggest to use the following one:
CONFIG_DEBUG_KERNEL=y
CONFIG_MAGIC_SYSRQ=y
# CONFIG_SCHEDSTATS is not set
# CONFIG_DEBUG_SLAB is not set
# CONFIG_DEBUG_PREEMPT is not set
# CONFIG_DEBUG_SPINLOCK_SLEEP is not set
CONFIG_WAKEUP_TIMING=y
# CONFIG_CRITICAL_PREEMPT_TIMING is not set
# CONFIG_CRITICAL_IRQSOFF_TIMING is not set
CONFIG_LATENCY_TIMING=y
CONFIG_LATENCY_TRACE=y
CONFIG_MCOUNT=y
# CONFIG_RT_DEADLOCK_DETECT is not set
# CONFIG_DEBUG_KOBJECT is not set
CONFIG_DEBUG_BUGVERBOSE=y
# CONFIG_DEBUG_INFO is not set
CONFIG_FRAME_POINTER=y
CONFIG_EARLY_PRINTK=y
# CONFIG_DEBUG_STACKOVERFLOW is not set
especially PREEMPT_TIMING, IRQSOFF_TIMING and RT_DEADLOCK_DETECT are
quite expensive options.
Ingo
* Rui Nuno Capela <[email protected]> wrote:
> xruntrace1.0.tar.gz
> - scripts used for xrun trace capture automation
>
> xruntrace1-2.6.10-rc2-mm3-RT-V0.7.31-7.tar.gz
> - actual xrun traces captured while running jackd on RT-V0.7.31-7
the trace buffer is too small to capture a significant portion of the
xrun - i'd suggest for you to increase it from 4096-1 to 4096*16-1, to
be able to capture a couple of hundreds of millisecs worth of traces.
also, i think it produces more stable results if the tracing is
activated and deactivated from userspace - i.e. the patch below will
measure the latency of poll() executed by the ALSA glue code within
JACK. (i also removed the xrun printf, because it can cause delays.)
this patch can be used the following way: do not activate xrun_debug via
/proc (to not create additional latencies that make xruns worse), but
otherwise set the /proc/sys/kernel/ flags the same way you do already.
If the patch is applied to jackd then /proc/latency_trace will show the
latest and highest latency that was measured.
note that this captures latencies visible in the ALSA glue, which doesnt
cover the whole jackd critical path - but it should be pretty good as an
initial start. It will definitely show all jackd-unrelated delay
sources.
to cover all latency paths, the last chunk of the patch could perhaps be
modified to do:
+ gettimeofday(1,0);
+ gettimeofday(1,1);
this will also capture latencies within jackd itself. But i think it is
better to separate 'external' from 'internal' latencies, because the two
situations are quite different and it might be hard to identify which
particular latency we are seeing in /proc/latency_trace.
Ingo
--- ./drivers/alsa/alsa_driver.c.orig 2004-11-26 14:11:26.000000000 +0100
+++ ./drivers/alsa/alsa_driver.c 2004-11-26 14:24:41.000000000 +0100
@@ -1081,9 +1081,11 @@ alsa_driver_xrun_recovery (alsa_driver_t
snd_pcm_status_get_trigger_tstamp(status, &tstamp);
timersub(&now, &tstamp, &diff);
*delayed_usecs = diff.tv_sec * 1000000.0 + diff.tv_usec;
+#if 0
fprintf(stderr, "\n\n**** alsa_pcm: xrun of at least %.3f "
"msecs\n\n",
*delayed_usecs / 1000.0);
+#endif
}
if (alsa_driver_stop (driver) ||
@@ -1187,6 +1189,7 @@ alsa_driver_wait (alsa_driver_t *driver,
poll_enter = jack_get_microseconds ();
+ gettimeofday(1,1);
if (poll (driver->pfd, nfds, driver->poll_timeout) < 0) {
if (errno == EINTR) {
@@ -1206,6 +1209,7 @@ alsa_driver_wait (alsa_driver_t *driver,
return 0;
}
+ gettimeofday(1,0);
poll_ret = jack_get_microseconds ();
* Ingo Molnar <[email protected]> wrote:
> --- ./drivers/alsa/alsa_driver.c.orig 2004-11-26 14:11:26.000000000 +0100
> +++ ./drivers/alsa/alsa_driver.c 2004-11-26 14:24:41.000000000 +0100
i think the one below is a better approach - it will only trace events
that the ALSA driver has reported to be an xrun. I.e. the full latency
path from the point where poll() is called, up to the point where jackd
[after the latency has occured] considers it an xrun worth
counting/reporting. The tracing restarts at every poll(), so only the
latency is captured. If you up your tracebuffer to 40K+ entries then i'd
suggest to use the following trace settings:
echo 0 > /proc/asound/card0/pcm0p/xrun_debug
echo 1 > /proc/sys/kernel/trace_user_triggered
echo 0 > /proc/sys/kernel/trace_freerunning
echo 0 > /proc/sys/kernel/preempt_max_latency
echo 0 > /proc/sys/kernel/preempt_thresh
echo 0 > /proc/sys/kernel/preempt_wakeup_timing
i.e. dont use trace_freerunning - this will give much easier to parse
traces.
a suggestion wrt. the format of the .trc files: it would be nice if you
could dump the PIDs of all relevant tasks into it too, to make it easier
to identify who causes what latency. Ideally it would be useful to
have a more symbolic trace - i.e. instead of:
3570 00000000 254981.991ms (+0.000ms): up (ext3_orphan_del)
it would be:
jackd-3570 00000000 254981.991ms (+0.000ms): up (ext3_orphan_del)
but this is easier done in the kernel - some of the tasks involved in a
latency might be long gone by the time you detect the xrun.
Ingo
--- ./drivers/alsa/alsa_driver.c.orig 2004-11-26 14:11:26.000000000 +0100
+++ ./drivers/alsa/alsa_driver.c 2004-11-26 15:31:37.000000000 +0100
@@ -1077,13 +1077,16 @@ alsa_driver_xrun_recovery (alsa_driver_t
&& driver->process_count > XRUN_REPORT_DELAY) {
struct timeval now, diff, tstamp;
driver->xrun_count++;
+ gettimeofday(0,0);
gettimeofday(&now, 0);
snd_pcm_status_get_trigger_tstamp(status, &tstamp);
timersub(&now, &tstamp, &diff);
*delayed_usecs = diff.tv_sec * 1000000.0 + diff.tv_usec;
+#if 0
fprintf(stderr, "\n\n**** alsa_pcm: xrun of at least %.3f "
"msecs\n\n",
*delayed_usecs / 1000.0);
+#endif
}
if (alsa_driver_stop (driver) ||
@@ -1185,6 +1188,7 @@ alsa_driver_wait (alsa_driver_t *driver,
nfds++;
}
+ gettimeofday(0,1);
poll_enter = jack_get_microseconds ();
if (poll (driver->pfd, nfds, driver->poll_timeout) < 0) {
Ingo Molnar wrote:
>
> * Rui Nuno Capela wrote:
>
>> xruntrace1.0.tar.gz
>> - scripts used for xrun trace capture automation
>>
>> xruntrace1-2.6.10-rc2-mm3-RT-V0.7.31-7.tar.gz
>> - actual xrun traces captured while running jackd on RT-V0.7.31-7
>
> the trace buffer is too small to capture a significant portion of the
> xrun - i'd suggest for you to increase it from 4096-1 to 4096*16-1, to
> be able to capture a couple of hundreds of millisecs worth of traces.
>
and how I do that? Is it some /proc magic or its in the kernel configuration?
please forgive my ignorance:)
bye.
--
rncbc aka Rui Nuno Capela
[email protected]
* Rui Nuno Capela <[email protected]> wrote:
> > the trace buffer is too small to capture a significant portion of the
> > xrun - i'd suggest for you to increase it from 4096-1 to 4096*16-1, to
> > be able to capture a couple of hundreds of millisecs worth of traces.
> >
>
> and how I do that? Is it some /proc magic or its in the kernel configuration?
it's the MAX_TRACE define in kernel/latency.c.
but please try to the -31-10 kernel that i've just uploaded, it has a
number of tracer enhancements:
- process name tracking. The new format is:
bash- 3633 80000003 0.264ms (+0.000ms): idle_cpu (wake_idle)
bash- 3633 80000003 0.264ms (+0.000ms): idle_cpu (wake_idle)
bash- 3633 80000003 0.264ms (+0.000ms): find_next_bit (wake_idle)
this makes it easier to identify which process does what. This feature
has no significant overhead in the tracer itself, all the hard work is
done when /proc/latency_trace is read by the user.
- /proc/sys/kernel/mcount_enabled flag: if disabled then
/proc/latency_trace will only contain 'custom' events, but no
per-function entries. This can be useful to trace really long
latencies, to get a rough idea of what is going on.
- /proc/latency_trace atomicity. It was fundamentally non-atomic, due
to it being a 4K-granular file interface. Now the kernel has a second
layer of saved-trace logic, which makes sure that the only time the
trace is switched is when the header of the trace is read. I.e. when
cp-ing or cat-ing /proc/latency_trace, no new trace info will be
used. This change could solve some of the 'truncated traces'
weirdnesses reported.
Ingo
* Ingo Molnar <[email protected]> wrote:
> but please try to the -31-10 kernel that i've just uploaded, it has a
> number of tracer enhancements:
make that -31-13 (or later). Earlier kernels had a bug in where the
process name tracking only worked for the first latency trace saved,
subsequent traces showed 'unknown' for the process name. In -13 i've
also added a printk that shows the latest user latency in a one-line
printk - just like the built-in latency tracing modes do:
(gettimeofday/3671/CPU#0): new 3068 us user-latency.
(gettimeofday/3784/CPU#0): new 1008627 us user-latency.
(this should also make it easier for helper scripts to save the traces,
whenever they happen.)
Ingo
> > --- ./drivers/alsa/alsa_driver.c.orig 2004-11-26 14:11:26.000000000 +0100
> > +++ ./drivers/alsa/alsa_driver.c 2004-11-26 14:24:41.000000000 +0100
find yet another approach below - it aborts jackd when the first xrun
happens. Since an xrun can trigger other xruns, the most reliable trace
would be the first xrun that triggers.
Ingo
--- ./drivers/alsa/alsa_driver.c.orig 2004-11-26 14:11:26.000000000 +0100
+++ ./drivers/alsa/alsa_driver.c 2004-11-29 17:39:15.985918576 +0100
@@ -1077,13 +1077,17 @@ alsa_driver_xrun_recovery (alsa_driver_t
&& driver->process_count > XRUN_REPORT_DELAY) {
struct timeval now, diff, tstamp;
driver->xrun_count++;
+ gettimeofday(0,0);
gettimeofday(&now, 0);
snd_pcm_status_get_trigger_tstamp(status, &tstamp);
timersub(&now, &tstamp, &diff);
*delayed_usecs = diff.tv_sec * 1000000.0 + diff.tv_usec;
+#if 1
fprintf(stderr, "\n\n**** alsa_pcm: xrun of at least %.3f "
"msecs\n\n",
*delayed_usecs / 1000.0);
+#endif
+ exit(-1);
}
if (alsa_driver_stop (driver) ||
@@ -1185,6 +1189,7 @@ alsa_driver_wait (alsa_driver_t *driver,
nfds++;
}
+ gettimeofday(0,1);
poll_enter = jack_get_microseconds ();
if (poll (driver->pfd, nfds, driver->poll_timeout) < 0) {
Hi Ingo,
I'm getting this error with V0.7.31-13
CC kernel/wait.o
CC kernel/kfifo.o
CC kernel/sys_ni.o
CC kernel/rt.o
CC kernel/latency.o
kernel/latency.c: In function `check_critical_timing':
kernel/latency.c:730: too few arguments to function `___trace'
kernel/latency.c:730: warning: too few arguments passed to inline
function, suppressing inlining
kernel/latency.c: In function `__start_critical_timing':
kernel/latency.c:810: incompatible type for argument 1 of `____trace'
kernel/latency.c:810: warning: passing arg 2 of `____trace' makes
pointer from integer without a cast
kernel/latency.c:810: too few arguments to function `____trace'
kernel/latency.c: In function `trace_irqs_off':
kernel/latency.c:810: warning: too few arguments passed to inline
function, suppressing inlining
kernel/latency.c: In function `add_preempt_count':
kernel/latency.c:810: warning: too few arguments passed to inline
function, suppressing inlining
kernel/latency.c: At top level:
kernel/latency.c:810: warning: too few arguments passed to inline
function, suppressing inlining
make[1]: *** [kernel/latency.o] Error 1
make: *** [kernel] Error 2
[root@tigre01 im]#
Regards
Remi
On Monday 29 November 2004 10:23, Ingo Molnar wrote:
>* Ingo Molnar <[email protected]> wrote:
>> but please try to the -31-10 kernel that i've just uploaded, it
>> has a number of tracer enhancements:
>
>make that -31-13 (or later). Earlier kernels had a bug in where the
>process name tracking only worked for the first latency trace saved,
>subsequent traces showed 'unknown' for the process name. In -13 i've
>also added a printk that shows the latest user latency in a one-line
>printk - just like the built-in latency tracing modes do:
>
> (gettimeofday/3671/CPU#0): new 3068 us user-latency.
> (gettimeofday/3784/CPU#0): new 1008627 us user-latency.
>
>(this should also make it easier for helper scripts to save the
> traces, whenever they happen.)
>
> Ingo
I just built this to see how much blood it would draw, which isn't
much. I don't have jack here, so I don't have your standard torture
test. Instead, I run tvtime, which runs at a -19 priority.
I let it run about 30 seconds (untimed), noted that the frame error
slippage wasn't improved, and got this output histogram when I quit
it.
Its (tvtime) is running here of course.
--------------------
Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
Nov 29 18:05:45 coyote kernel: wow! That was a 22 millisec bump
Nov 29 18:05:45 coyote kernel: `IRQ 8'[846] is being piggy.
need_resched=0, cpu=0
Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
Nov 29 18:05:45 coyote kernel: wow! That was a 22 millisec bump
Nov 29 18:05:45 coyote kernel: `IRQ 8'[846] is being piggy.
need_resched=0, cpu=0
Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
Nov 29 18:05:45 coyote kernel: wow! That was a 21 millisec bump
Nov 29 18:05:45 coyote kernel: `IRQ 8'[846] is being piggy.
need_resched=0, cpu=0
Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
Nov 29 18:05:45 coyote kernel: wow! That was a 21 millisec bump
Nov 29 18:05:45 coyote kernel: `IRQ 8'[846] is being piggy.
need_resched=0, cpu=0
Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
Nov 29 18:05:45 coyote kernel:
And was stopped here.
Nov 29 18:05:45 coyote kernel: rtc latency histogram of {tvtime/3398,
10609 samples}:
Nov 29 18:05:45 coyote kernel: 4 11
Nov 29 18:05:45 coyote kernel: 5 1716
Nov 29 18:05:45 coyote kernel: 6 4827
Nov 29 18:05:45 coyote kernel: 7 1495
Nov 29 18:05:45 coyote kernel: 8 382
Nov 29 18:05:45 coyote kernel: 9 193
Nov 29 18:05:45 coyote kernel: 10 206
Nov 29 18:05:45 coyote kernel: 11 188
Nov 29 18:05:45 coyote kernel: 12 148
Nov 29 18:05:45 coyote kernel: 13 202
Nov 29 18:05:45 coyote kernel: 14 195
Nov 29 18:05:45 coyote kernel: 15 95
Nov 29 18:05:45 coyote kernel: 16 70
Nov 29 18:05:45 coyote kernel: 17 23
Nov 29 18:05:45 coyote kernel: 18 18
Nov 29 18:05:45 coyote kernel: 19 8
Nov 29 18:05:45 coyote kernel: 20 9
Nov 29 18:05:45 coyote kernel: 21 1
Nov 29 18:05:45 coyote kernel: 22 1
Nov 29 18:05:45 coyote kernel: 26 1
--------------------
And I note that the 1-26 column of numbers does not seem to add up to
whats being logged above there, which are all 21 and 22 ms bumps
(whatever a bump is)
Is this a helpfull report, or just noise? Subjectively, tvtime is
running with far fewer visible frame glitches than before I started
playing with these patches. A marked improvement IMO.
--
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.29% 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.
Gene Heskett wrote:
> On Monday 29 November 2004 10:23, Ingo Molnar wrote:
>
>>* Ingo Molnar <[email protected]> wrote:
>>
>>>but please try to the -31-10 kernel that i've just uploaded, it
>>>has a number of tracer enhancements:
>>
>>make that -31-13 (or later). Earlier kernels had a bug in where the
>>process name tracking only worked for the first latency trace saved,
>>subsequent traces showed 'unknown' for the process name. In -13 i've
>>also added a printk that shows the latest user latency in a one-line
>>printk - just like the built-in latency tracing modes do:
>>
>>(gettimeofday/3671/CPU#0): new 3068 us user-latency.
>>(gettimeofday/3784/CPU#0): new 1008627 us user-latency.
>>
>>(this should also make it easier for helper scripts to save the
>>traces, whenever they happen.)
>>
>>Ingo
>
>
> I just built this to see how much blood it would draw, which isn't
> much. I don't have jack here, so I don't have your standard torture
> test. Instead, I run tvtime, which runs at a -19 priority.
>
> I let it run about 30 seconds (untimed), noted that the frame error
> slippage wasn't improved, and got this output histogram when I quit
> it.
>
> Its (tvtime) is running here of course.
> --------------------
> Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
> Nov 29 18:05:45 coyote kernel: wow! That was a 22 millisec bump
> Nov 29 18:05:45 coyote kernel: `IRQ 8'[846] is being piggy.
> need_resched=0, cpu=0
> Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
> Nov 29 18:05:45 coyote kernel: wow! That was a 22 millisec bump
> Nov 29 18:05:45 coyote kernel: `IRQ 8'[846] is being piggy.
> need_resched=0, cpu=0
> Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
> Nov 29 18:05:45 coyote kernel: wow! That was a 21 millisec bump
> Nov 29 18:05:45 coyote kernel: `IRQ 8'[846] is being piggy.
> need_resched=0, cpu=0
> Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
> Nov 29 18:05:45 coyote kernel: wow! That was a 21 millisec bump
> Nov 29 18:05:45 coyote kernel: `IRQ 8'[846] is being piggy.
> need_resched=0, cpu=0
> Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
> Nov 29 18:05:45 coyote kernel:
>
> And was stopped here.
>
> Nov 29 18:05:45 coyote kernel: rtc latency histogram of {tvtime/3398,
> 10609 samples}:
> Nov 29 18:05:45 coyote kernel: 4 11
> Nov 29 18:05:45 coyote kernel: 5 1716
> Nov 29 18:05:45 coyote kernel: 6 4827
> Nov 29 18:05:45 coyote kernel: 7 1495
> Nov 29 18:05:45 coyote kernel: 8 382
> Nov 29 18:05:45 coyote kernel: 9 193
> Nov 29 18:05:45 coyote kernel: 10 206
> Nov 29 18:05:45 coyote kernel: 11 188
> Nov 29 18:05:45 coyote kernel: 12 148
> Nov 29 18:05:45 coyote kernel: 13 202
> Nov 29 18:05:45 coyote kernel: 14 195
> Nov 29 18:05:45 coyote kernel: 15 95
> Nov 29 18:05:45 coyote kernel: 16 70
> Nov 29 18:05:45 coyote kernel: 17 23
> Nov 29 18:05:45 coyote kernel: 18 18
> Nov 29 18:05:45 coyote kernel: 19 8
> Nov 29 18:05:45 coyote kernel: 20 9
> Nov 29 18:05:45 coyote kernel: 21 1
> Nov 29 18:05:45 coyote kernel: 22 1
> Nov 29 18:05:45 coyote kernel: 26 1
> --------------------
> And I note that the 1-26 column of numbers does not seem to add up to
> whats being logged above there, which are all 21 and 22 ms bumps
> (whatever a bump is)
Is this all that is in the log? For some reason there are 820 samples
not represented in the output above. The ms+ hits would have been
represented by something like:
Nov 29 18:05:45 coyote kernel: 9999 4
Not that it is related to the missing output, but does tvtime use
polling on the rtc?
kr
>
> Is this a helpfull report, or just noise? Subjectively, tvtime is
> running with far fewer visible frame glitches than before I started
> playing with these patches. A marked improvement IMO.
>
On Monday 29 November 2004 20:50, K.R. Foley wrote:
>Gene Heskett wrote:
>> On Monday 29 November 2004 10:23, Ingo Molnar wrote:
>>>* Ingo Molnar <[email protected]> wrote:
>>>>but please try to the -31-10 kernel that i've just uploaded, it
>>>>has a number of tracer enhancements:
>>>
>>>make that -31-13 (or later). Earlier kernels had a bug in where
>>> the process name tracking only worked for the first latency trace
>>> saved, subsequent traces showed 'unknown' for the process name.
>>> In -13 i've also added a printk that shows the latest user
>>> latency in a one-line printk - just like the built-in latency
>>> tracing modes do:
>>>
>>>(gettimeofday/3671/CPU#0): new 3068 us user-latency.
>>>(gettimeofday/3784/CPU#0): new 1008627 us user-latency.
>>>
>>>(this should also make it easier for helper scripts to save the
>>>traces, whenever they happen.)
>>>
>>>Ingo
>>
>> I just built this to see how much blood it would draw, which isn't
>> much. I don't have jack here, so I don't have your standard
>> torture test. Instead, I run tvtime, which runs at a -19
>> priority.
>>
>> I let it run about 30 seconds (untimed), noted that the frame
>> error slippage wasn't improved, and got this output histogram when
>> I quit it.
>>
>> Its (tvtime) is running here of course.
>> --------------------
>> Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
>> Nov 29 18:05:45 coyote kernel: wow! That was a 22 millisec bump
>> Nov 29 18:05:45 coyote kernel: `IRQ 8'[846] is being piggy.
>> need_resched=0, cpu=0
>> Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
>> Nov 29 18:05:45 coyote kernel: wow! That was a 22 millisec bump
>> Nov 29 18:05:45 coyote kernel: `IRQ 8'[846] is being piggy.
>> need_resched=0, cpu=0
>> Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
>> Nov 29 18:05:45 coyote kernel: wow! That was a 21 millisec bump
>> Nov 29 18:05:45 coyote kernel: `IRQ 8'[846] is being piggy.
>> need_resched=0, cpu=0
>> Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
>> Nov 29 18:05:45 coyote kernel: wow! That was a 21 millisec bump
>> Nov 29 18:05:45 coyote kernel: `IRQ 8'[846] is being piggy.
>> need_resched=0, cpu=0
>> Nov 29 18:05:45 coyote kernel: Read missed before next interrupt
>> Nov 29 18:05:45 coyote kernel:
>>
>> And was stopped here.
>>
>> Nov 29 18:05:45 coyote kernel: rtc latency histogram of
>> {tvtime/3398, 10609 samples}:
>> Nov 29 18:05:45 coyote kernel: 4 11
>> Nov 29 18:05:45 coyote kernel: 5 1716
>> Nov 29 18:05:45 coyote kernel: 6 4827
>> Nov 29 18:05:45 coyote kernel: 7 1495
>> Nov 29 18:05:45 coyote kernel: 8 382
>> Nov 29 18:05:45 coyote kernel: 9 193
>> Nov 29 18:05:45 coyote kernel: 10 206
>> Nov 29 18:05:45 coyote kernel: 11 188
>> Nov 29 18:05:45 coyote kernel: 12 148
>> Nov 29 18:05:45 coyote kernel: 13 202
>> Nov 29 18:05:45 coyote kernel: 14 195
>> Nov 29 18:05:45 coyote kernel: 15 95
>> Nov 29 18:05:45 coyote kernel: 16 70
>> Nov 29 18:05:45 coyote kernel: 17 23
>> Nov 29 18:05:45 coyote kernel: 18 18
>> Nov 29 18:05:45 coyote kernel: 19 8
>> Nov 29 18:05:45 coyote kernel: 20 9
>> Nov 29 18:05:45 coyote kernel: 21 1
>> Nov 29 18:05:45 coyote kernel: 22 1
>> Nov 29 18:05:45 coyote kernel: 26 1
>> --------------------
>> And I note that the 1-26 column of numbers does not seem to add up
>> to whats being logged above there, which are all 21 and 22 ms
>> bumps (whatever a bump is)
>
>Is this all that is in the log? For some reason there are 820
> samples not represented in the output above. The ms+ hits would
> have been represented by something like:
>
>Nov 29 18:05:45 coyote kernel: 9999 4
There are NO lines in the log that look like that. There are many
hundred duplicates of the 3 line pattern you see at the top of the
snip, but thats it.
AND I just discovered that I am not running the -13 kernel, but the -7
version as I had that entry set as the fallback in grub.conf. I've
since reset that to the -9 kernel as fallback and thats whats running
right now.
Which brings up something thats been an excedrin headache here since I
bought this #*&^^$^% ati 9200-SE video card to replace a failed
nvidia that took the motherboard with it when it failed. Thats the
fact that I boot blind. From the grub screen to the start of the
rc.sysinit script, this machine has no fonts! Sure, I see the curser
dancing back and forth over the bottom line of the screen, but
nothing is displayed, and this is true whether the fonts are compiled
in or as modules, whether the radeonfb is compiled in or as a module,
and with or without the VGA(16) or vesafb, compiled in or as a
module.
So its doing an automatic reboot to the kernel set as default, and
doing it during the time that I am blind from a lack of fonts.
FWIW, I've mentioned this on a couple of occasions but no one has
commented one way or the other.
One thing I haven't tried is to take all frame buffers out of the
kernel, not even as available modules, in order to force it to use
the cards own display. That would effectively convert this machine
into a 66 mhz 486, but I guess its worth the test. I'll be back
after trying that.
>
>Not that it is related to the missing output, but does tvtime use
>polling on the rtc?
Sorry. All I can tell you is that I did have to put the rtc into the
kernel before tvtime would run well at all.
>kr
--
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.29% 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.
On Monday 29 November 2004 20:50, K.R. Foley wrote:
>Gene Heskett wrote:
>>>make that -31-13 (or later). Earlier kernels had a bug in where
[...]
>Is this all that is in the log? For some reason there are 820
> samples not represented in the output above. The ms+ hits would
> have been represented by something like:
>
>Nov 29 18:05:45 coyote kernel: 9999 4
Ok, I finally got -13 to run (typo in grub), and you are now correct
in that the final entry in the log after I shut tvtime down is like
this:
Nov 29 23:43:40 coyote kernel: rtc latency histogram of {tvtime/3911,
10430 samples}:
Nov 29 23:43:40 coyote kernel: 4 51
Nov 29 23:43:40 coyote kernel: 5 2058
Nov 29 23:43:40 coyote kernel: 6 3594
Nov 29 23:43:40 coyote kernel: 7 1270
Nov 29 23:43:40 coyote kernel: 8 473
Nov 29 23:43:40 coyote kernel: 9 299
Nov 29 23:43:40 coyote kernel: 10 252
Nov 29 23:43:40 coyote kernel: 11 209
Nov 29 23:43:40 coyote kernel: 12 215
Nov 29 23:43:40 coyote kernel: 13 345
Nov 29 23:43:40 coyote kernel: 14 391
Nov 29 23:43:40 coyote kernel: 15 248
Nov 29 23:43:40 coyote kernel: 16 113
Nov 29 23:43:40 coyote kernel: 17 55
Nov 29 23:43:40 coyote kernel: 18 17
Nov 29 23:43:40 coyote kernel: 19 11
Nov 29 23:43:40 coyote kernel: 20 4
Nov 29 23:43:40 coyote kernel: 21 1
Nov 29 23:43:40 coyote kernel: 23 2
Nov 29 23:43:40 coyote kernel: 28 1
Nov 29 23:43:40 coyote kernel: 4612 1
Nov 29 23:43:40 coyote kernel: 9999 820
What does this tell you now? The last 2 lines look a bit strange to
me. Particularly since the runtime was random enough that your
previous comment about the number 820 was a mssing count, and what
came out of a seperate run IS an 820.
I find that a bit hard to believe that I timed those two runs
identically.
--
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.29% 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.
> Hi Ingo,
>
> I'm getting this error with V0.7.31-13
>
...
> CC kernel/latency.o
> kernel/latency.c: In function `check_critical_timing':
> kernel/latency.c:730: too few arguments to function `___trace'
> kernel/latency.c:730: warning: too few arguments passed to inline function, suppressing inlining
> kernel/latency.c: In function `__start_critical_timing':
> kernel/latency.c:810: incompatible type for argument 1 of `____trace'
> kernel/latency.c:810: warning: passing arg 2 of `____trace' makes pointer from integer without a cast
...
> kernel/latency.c:810: warning: too few arguments passed to inline function, suppressing inlining
> make[1]: *** [kernel/latency.o] Error 1
> make: *** [kernel] Error 2
> [root@tigre01 im]#
>
> Regards
> Remi
I'm guessing here, but with the following patch it at least compiles:
--- kernel/latency.c.orig 2004-11-28 21:32:04.757015856 +0200
+++ kernel/latency.c 2004-11-28 21:28:28.000000000 +0200
@@ -727,7 +727,7 @@
tr->critical_end = parent_eip;
#ifdef CONFIG_LATENCY_TRACE
- ___trace(CALLER_ADDR0, parent_eip);
+ ___trace(TRACE_FN, CALLER_ADDR0, parent_eip, 0, 0, 0);
update_max_trace(tr);
#endif
@@ -807,7 +807,7 @@
tr->critical_start = eip;
#ifdef CONFIG_LATENCY_TRACE
tr->trace_idx = 0;
- ____trace(tr, eip, parent_eip, 0, 0, 0);
+ ____trace(TRACE_FN, tr, eip, parent_eip, 0, 0, 0);
#endif
atomic_dec(&tr->disabled);
--
Eran Mann
Senior Software Engineer
MRV International
Tel: 972-4-9936297
Fax: 972-4-9890430
http://www.mrv.com
* Remi Colinet <[email protected]> wrote:
> Hi Ingo,
>
> I'm getting this error with V0.7.31-13
> CC kernel/latency.o
> kernel/latency.c: In function `check_critical_timing':
> kernel/latency.c:730: too few arguments to function `___trace'
> kernel/latency.c:730: warning: too few arguments passed to inline
fixed this in -V0.7.31-14.
Ingo
* Eran Mann <[email protected]> wrote:
> I'm guessing here, but with the following patch it at least compiles:
yeah, this is the correct patch, included in the -31-14 and later
patches.
Ingo
Ingo Molnar wrote:
>
> * Ingo Molnar <[email protected]> wrote:
>
>> but please try to the -31-10 kernel that i've just uploaded, it has a
>> number of tracer enhancements:
>
> make that -31-13 (or later). Earlier kernels had a bug in where the
> process name tracking only worked for the first latency trace saved,
> subsequent traces showed 'unknown' for the process name. In -13 i've
> also added a printk that shows the latest user latency in a one-line
> printk - just like the built-in latency tracing modes do:
>
> (gettimeofday/3671/CPU#0): new 3068 us user-latency.
> (gettimeofday/3784/CPU#0): new 1008627 us user-latency.
>
> (this should also make it easier for helper scripts to save the traces,
> whenever they happen.)
>
OK.
I did my homework and managed to grab some latency traces for you to take
a look and see if it's alright. Please.
On attach you may find the files:
xruntrace1.1.tar.gz
- scripts used to arm and capture the latency traces;
jack-0.99.14.0xruntrace-alsa.patch.gz
- the actual patch applied to jack for trace auto-triggering;
config-2.6.10-rc2-mm3-RT-V0.7.31-13.gz
- the running kernel configuration, as taken from /proc/config.gz
xruntrace1-2.6.10-rc2-mm3-RT-V0.7.31-13-*.trc.gz
- the captured traces, as dumped with xruntrace1_watch.sh script.
jack_test3.2.tar.gz
- updated my jack_test3 benchmarking suite.
The traces were captured, while running a usual KDE desktop session (from
qjackctl) on my [email protected] laptop (Mandrake 10.1):
jackd -R -P60 -dalsa -dhw:0 -r44100 -p64 -n2 -S -P
Each trace shows only the first XRUN occurrence on a distinct jackd
session. Every other trace were triggered and captured after restarting
jackd.
Must say that XRUNs are rare but do occurr. Using the same jackd command
line, my jack_test3 suite is showing these figures by now:
*********** CONSOLIDATED RESULTS ************
Total seconds ran . . . . . . : 7200
Number of clients . . . . . . : 16
Ports per client . . . . . . : 4
*********************************************
Summary Result Count . . . . : 2 / 2
*********************************************
Timeout Rate . . . . . . . . :( 0.0)/hour
XRUN Rate . . . . . . . . . . : 13.8 /hour
Delay Rate (>spare time) . . : 13.8 /hour
Delay Rate (>1000 usecs) . . : 7.0 /hour
Delay Maximum . . . . . . . . : 1022 usecs
Cycle Maximum . . . . . . . . : 1048 usecs
Average DSP Load. . . . . . . : 62.2 %
Average CPU System Load . . . : 20.6 %
Average CPU User Load . . . . : 48.5 %
Average CPU Nice Load . . . . : 0.0 %
Average CPU I/O Wait Load . . : 0.0 %
Average CPU IRQ Load . . . . : 0.0 %
Average CPU Soft-IRQ Load . . : 0.0 %
Average Interrupt Rate . . . : 1689.2 /sec
Average Context-Switch Rate . : 19778.2 /sec
*********************************************
The IRQ process/threading priority status has been fixed as shown below:
PID CLS RTPRIO NI PRI %CPU STAT COMMAND
2 FF 90 - 130 0.0 S IRQ 0
728 FF 80 - 120 0.0 S< IRQ 8
2943 FF 70 - 110 0.0 S< IRQ 5
1500 FF 60 - 100 0.0 S< IRQ 10
841 FF 50 - 90 0.0 S< IRQ 1
736 FF 49 - 89 0.0 S< IRQ 12
20 FF 48 - 88 0.0 S< IRQ 9
814 FF 45 - 85 0.0 S< IRQ 6
821 FF 44 - 84 0.0 S< IRQ 14
823 FF 43 - 83 0.0 S< IRQ 15
2227 FF 40 - 80 0.0 S< IRQ 11
# cat /proc/interrupts
CPU0
0: 6435186 XT-PIC timer 0/35186
1: 1164 XT-PIC i8042 1/1164
2: 0 XT-PIC cascade 0/0
5: 73 XT-PIC ALI 5451 0/72
8: 1 XT-PIC rtc 0/1
9: 20602 XT-PIC acpi 0/20602
10: 0 XT-PIC ohci_hcd, ohci_hcd 0/0
11: 5 XT-PIC yenta 5/5
12: 64317 XT-PIC i8042 0/64317
14: 11772 XT-PIC ide0 0/11772
15: 19 XT-PIC ide1 0/19
NMI: 0
LOC: 0
ERR: 0
MIS: 0
Cheers.
--
rncbc aka Rui Nuno Capela
[email protected]
* Rui Nuno Capela <[email protected]> wrote:
> xruntrace1-2.6.10-rc2-mm3-RT-V0.7.31-13-*.trc.gz
> - the captured traces, as dumped with xruntrace1_watch.sh script.
> Each trace shows only the first XRUN occurrence on a distinct jackd
> session. Every other trace were triggered and captured after
> restarting jackd.
interesting - the trace shows only a latency of 20-40 usecs. Perhaps the
tracing should be done over two periods?
Could you try to hack alsa_driver.c to do the gettimeofday(1,1) call for
only every second case. Something like this ought to be enough:
{
static count = 0;
if (!(count++ & 1))
gettimeofday(0,1);
}
(only one thread accesses this particular variable so there are no
threading issues.)
with this variant there's a 50% chance that we get the trace of the last
2 poll() instances. (and there's a 50% chance that we get only 1 period
covered.)
in any case, the scripts & approach seems to be almost there, i hope we
only need the above change to see the true source of the xruns.
Ingo
I have results from two builds of -V0.7.31-9. The first
build is CONFIG_RT (RT) and the second is CONFIG_DESKTOP (PK or
as described in .config help - Preempt Kernel).
Both booted OK - so the SMP lockup on _DESKTOP appears to
be fixed. Both ran my test series faster than previous 2.6
kernels. I was seeing run times over 30 minutes before
(mainly due to starvation of non-RT tasks) but both completed
in about 20 minutes.
General notes:
[1] Audio duration was much more variable on the PK than the
RT kernel. The variability on PK audio duration is about 30%
of nominal time. The RT kernel was less variable but tended to
finish well before the nominal time (and you could hear the
difference). The PK results look like buffering inside ALSA
that was not present in OSS?. Not sure why the RT kernel
is almost always finishing too soon.
[2] The PK kernel has much longer latencies as measured by
the in kernel tracing code. The RT kernel basically had NO
latencies > 50 usec where the PK kernel had several over a
millisecond (usually related to disk writes). By this measure
the RT kernel is clearly better.
[3] The overhead of RT (as measured by the CPU loop timing and
by pings from remote systems) is more than the PK kernel. I
believe this is due to the IRQ threading overhead. By these
measures, the PK kernel is better. By elapsed time, the 2.4
kernel is far superior.
More specifics:
The 2.4 numbers are from 2.4.24 w/ low latency / preempt patches.
within 100 usec
CPU loop (%) Elapsed Time (sec) 2.4
Test PK RT PK RT | CPU Elapsed
X 99.69 99.34 90 70 | 97.20 70
top 99.31 98.33 30 31 | 97.48 29
neto 97.28 97.69 205 315 | 96.23 36
neti 97.76 98.11 198 325 | 95.86 41
diskw 69.16* 94.98 51 115 | 77.64 29
diskc 96.44 98.39 230 250 | 84.12 77
diskr 99.60 98.77 240 180 | 90.66 86
total 1044 1286 | 368
* several multiple millisecond latencies measured by the
tracing code. Will send traces separately.
min ave max mdev
PK ping - 0.100 / 0.176 / 1.009 / 0.053
RT ping - 0.194 / 0.322 / 527.635 / 2.263
[not sure why the high max on RT, but I did see a few
1 msec or longer ping responses and many over 400 usec]
--Mark H Johnson
<mailto:[email protected]>
Gene Heskett wrote:
> On Monday 29 November 2004 20:50, K.R. Foley wrote:
>
>>Gene Heskett wrote:
>
>
>>>>make that -31-13 (or later). Earlier kernels had a bug in where
>
>
> [...]
>
>
>>Is this all that is in the log? For some reason there are 820
>>samples not represented in the output above. The ms+ hits would
>>have been represented by something like:
>>
>>Nov 29 18:05:45 coyote kernel: 9999 4
>
>
> Ok, I finally got -13 to run (typo in grub), and you are now correct
> in that the final entry in the log after I shut tvtime down is like
> this:
>
> Nov 29 23:43:40 coyote kernel: rtc latency histogram of {tvtime/3911,
> 10430 samples}:
> Nov 29 23:43:40 coyote kernel: 4 51
> Nov 29 23:43:40 coyote kernel: 5 2058
> Nov 29 23:43:40 coyote kernel: 6 3594
> Nov 29 23:43:40 coyote kernel: 7 1270
> Nov 29 23:43:40 coyote kernel: 8 473
> Nov 29 23:43:40 coyote kernel: 9 299
> Nov 29 23:43:40 coyote kernel: 10 252
> Nov 29 23:43:40 coyote kernel: 11 209
> Nov 29 23:43:40 coyote kernel: 12 215
> Nov 29 23:43:40 coyote kernel: 13 345
> Nov 29 23:43:40 coyote kernel: 14 391
> Nov 29 23:43:40 coyote kernel: 15 248
> Nov 29 23:43:40 coyote kernel: 16 113
> Nov 29 23:43:40 coyote kernel: 17 55
> Nov 29 23:43:40 coyote kernel: 18 17
> Nov 29 23:43:40 coyote kernel: 19 11
> Nov 29 23:43:40 coyote kernel: 20 4
> Nov 29 23:43:40 coyote kernel: 21 1
> Nov 29 23:43:40 coyote kernel: 23 2
> Nov 29 23:43:40 coyote kernel: 28 1
> Nov 29 23:43:40 coyote kernel: 4612 1
> Nov 29 23:43:40 coyote kernel: 9999 820
>
> What does this tell you now? The last 2 lines look a bit strange to
> me. Particularly since the runtime was random enough that your
> previous comment about the number 820 was a mssing count, and what
> came out of a seperate run IS an 820.
>
> I find that a bit hard to believe that I timed those two runs
> identically.
>
When I mentioned 820 that was just what was missing from the histogram
data vs. the total samples. As for why this number showed up again, dumb
luck? What the histogram represents is usecs (left column) between
interrupt and read. The right column is the number of occurrences. What
this tells me is that you had 820 samples that were greater than 9.999ms.
I took a brief look at the tvtime code. I noticed several things:
1) tvtime sets the interrupt frequency for the rtc to 1024 Hz which
would imply that you should have had roughly 30000 samples in a 30
second run, minus initial setup time. The histogram only shows 10430
samples. I have no way of knowing if the setup time is really that long
or if you are missing some interrupts. Unfortunately the rtc histogram
stuff doesn't currently track missed interrupts except to print out the
messages you were seeing
"<some process> is being piggy... Read missed before next interrupt"
2) tvtime is probably running at a RT priority of 99. The IRQ handler
for the rtc defaults to 48-49 (I think). If you didn't already do so,
you should bump the priority up as in:
chrt -f -p 99 `/sbin/pidof 'IRQ 8'`
Try that and see if it helps at all.
kr
> Ingo Molnar
>
> * Rui Nuno Capela wrote:
>
>> xruntrace1-2.6.10-rc2-mm3-RT-V0.7.31-13-*.trc.gz
>> - the captured traces, as dumped with xruntrace1_watch.sh
>> script.
>
>> Each trace shows only the first XRUN occurrence on a distinct jackd
>> session. Every other trace were triggered and captured after
>> restarting jackd.
>
> interesting - the trace shows only a latency of 20-40 usecs. Perhaps the
> tracing should be done over two periods?
>
> Could you try to hack alsa_driver.c to do the gettimeofday(1,1) call for
> only every second case. Something like this ought to be enough:
>
> {
> static count = 0;
>
> if (!(count++ & 1))
> gettimeofday(0,1);
> }
>
> (only one thread accesses this particular variable so there are no
> threading issues.)
>
> with this variant there's a 50% chance that we get the trace of the last
> 2 poll() instances. (and there's a 50% chance that we get only 1 period
> covered.)
>
> in any case, the scripts & approach seems to be almost there, i hope we
> only need the above change to see the true source of the xruns.
>
Done that.
New XRUN traces are attached, while running RT-V0.7.31-15 now. However, I
don't seem to get any notorious difference on the results, since previous
ones. All latencies traced ca. 26-27 usecs.
Bye.
--
rncbc aka Rui Nuno Capela
[email protected]
On Tuesday 30 November 2004 03:58, Ingo Molnar wrote:
>* Eran Mann <[email protected]> wrote:
>> I'm guessing here, but with the following patch it at least
>> compiles:
>
>yeah, this is the correct patch, included in the -31-14 and later
>patches.
>
> Ingo
I hadn't hit this one yet, up since about midnight with -13, and just
now found -15 so I'll build it.
--
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.29% 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.
On Tuesday 30 November 2004 10:26, K.R. Foley wrote:
>
>"<some process> is being piggy... Read missed before next interrupt"
>
>2) tvtime is probably running at a RT priority of 99. The IRQ
> handler for the rtc defaults to 48-49 (I think). If you didn't
> already do so, you should bump the priority up as in:
>
>chrt -f -p 99 `/sbin/pidof 'IRQ 8'`
[root@coyote root]# chrt -f -p 99 `/sbin/pidof 'IRQ 8'`
bash: chrt: command not found
chrt is an unknown command here. WTH? Basicly an FC2 system.
>Try that and see if it helps at all.
>
>kr
--
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.29% 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.
* Rui Nuno Capela <[email protected]> wrote:
> Done that.
>
> New XRUN traces are attached, while running RT-V0.7.31-15 now.
> However, I don't seem to get any notorious difference on the results,
> since previous ones. All latencies traced ca. 26-27 usecs.
hm, weird. Next idea: could you activate trace_freerunning and change
the alsa_driver.c count hack to do:
if (!count) {
gettimeofday(0,1);
count = 1;
}
this means that tracing will only be activated once, and the tracing
goes on non-stop from that point on, up until the first xrun, at which
point the full tracebuffer is saved. Ok?
Ingo
On Tue, 30 Nov 2004, Gene Heskett wrote:
> On Tuesday 30 November 2004 10:26, K.R. Foley wrote:
> >
> >"<some process> is being piggy... Read missed before next interrupt"
> >
> >2) tvtime is probably running at a RT priority of 99. The IRQ
> > handler for the rtc defaults to 48-49 (I think). If you didn't
> > already do so, you should bump the priority up as in:
> >
> >chrt -f -p 99 `/sbin/pidof 'IRQ 8'`
>
> [root@coyote root]# chrt -f -p 99 `/sbin/pidof 'IRQ 8'`
> bash: chrt: command not found
>
> chrt is an unknown command here. WTH? Basicly an FC2 system.
Install the package first (from an FC2 system)
zwane@r3000 ~ {0:1} rpm -qif `which chrt`
Name : schedutils Relocations: (not relocatable)
Version : 1.3.0 Vendor: Red Hat, Inc.
Release : 6 Build Date: Tue 17 Feb 2004
10:16:15 MST
Install Date: Tue 13 Jul 2004 11:13:52 MDT Build Host: tweety.devel.redhat.com
Group : Applications/System Source RPM: schedutils-1.3.0-6.src.rpm
Size : 39412 License: GPL
Signature : DSA/SHA1, Thu 06 May 2004 16:36:57 MDT, Key ID b44269d04f2a6fd2
Packager : Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>
Summary : Utilities for manipulating process scheduler attributes
Description : schedutils is a set of utilities for retrieving and
manipulating process scheduler-related attributes, such as real-time
parameters and CPU affinity.
This package includes the chrt and taskset utilities.
Install this package if you need to set or get scheduler-related
attributes.
Gene Heskett wrote:
> On Tuesday 30 November 2004 10:26, K.R. Foley wrote:
>
>>"<some process> is being piggy... Read missed before next interrupt"
>>
>>2) tvtime is probably running at a RT priority of 99. The IRQ
>>handler for the rtc defaults to 48-49 (I think). If you didn't
>>already do so, you should bump the priority up as in:
>>
>>chrt -f -p 99 `/sbin/pidof 'IRQ 8'`
>
>
> [root@coyote root]# chrt -f -p 99 `/sbin/pidof 'IRQ 8'`
> bash: chrt: command not found
>
> chrt is an unknown command here. WTH? Basicly an FC2 system.
It's part of schedutils pkg.
kr