Re: [PATCH] Preemption Latency Measurement Tool

[Dieter Nützel]

Am Freitag, 21. September 2001 17:48 schrieb george anzinger:
> Robert Love wrote:
> > On Thu, 2001-09-20 at 18:51, Dieter Nützel wrote:
> > > > Does your audio source depend on any files (eg mp3s) and if so, could
> > > > they be moved to a ramfs? Do the skips go away then?
> > >
> > > Good point.
> > >
> > > I've copied one video (MP2) and one Ogg-Vorbis file into /dev/shm.
> > > Little bit better but hiccup still there :-(
> >
> > As I've been saying, the problem really shouldn't be disk I/O.  I would
> > think (and really hope) the readahead code can fit a little mp3 in
> > memory.  Even if not, its a quick read to load it.  The continued blips
> > you see are caused by something, well, continual :)
>
> Are you running your application at some real time priority?  I suspect
> that, when dbench starts, it floods the system with a lot of new tasks
> and the system must visit each one until it gets back to your ap.  Nice
> will only do so much here.  Real time priority is the way to go.
> Attached are a couple of small programs to help here.  "rt" runs a given
> ap at a given priority.  I.e. > rt 10 foo, runs foo at priority 10.
> (There are more options, try rt -h.)  getrt reports the priority of a
> task.  If you do something like > rt 10 bash   everything you run from
> the new bash prompt will be at priority 10.  You must be root to run rt

Yes, I do like I've posted in all the related threads.

Here is some more input for you. I hope it could help nail it down.

Regards,
	Dieter

BTW I'll now switching to 2.4.10-pre14

SunWave1#time tar xIf /Pakete/Linux/linux-2.4.9.tar.bz2
34.570u 5.350s 0:47.84 83.4%    0+0k 0+0io 295pf+0w

I "hear" some have disk activities (disk trashing).

SunWave1#sync

Runs for ages!!!

User	 CPU  0%
System	 CPU  0%
Idle	 CPU 99%

So where did it wait???

Here comes what latencytimes show:

Worst 20 latency times of 5061 measured in this period.
  usec      cause     mask   start line/file      address   end line/file
322263   reacqBKL        1  1375/sched.c         c01138b4   697/sched.c
216174        BKL        1    30/inode.c         c016b971    52/inode.c
158328        BKL        9   742/block_dev.c     c0144d51   697/sched.c
 66975        BKL        1  1101/super.c         c014250d   697/sched.c
 53560        BKL        1  1101/super.c         c014250d  1130/super.c
 37742  spin_lock        1   547/sched.c         c0111b04   795/block_dev.c
 24822  spin_lock        1   678/inode.c         c01551f7   704/inode.c
 24739  spin_lock        1   291/buffer.c        c014003c   285/buffer.c
 19330  spin_lock        1   547/sched.c         c0111b04   697/sched.c
 16566        BKL        1    30/inode.c         c016b971   697/sched.c
 14049  spin_lock        1  2043/tcp_ipv6.c      e9078837   119/softirq.c
 11993  spin_lock        1  2111/tcp_ipv4.c      c0220517   119/softirq.c
 11704        BKL        1   706/block_dev.c     c0144bd7  1381/sched.c
 11405  spin_lock        1   291/buffer.c        c014003c   280/buffer.c
 11288        BKL        1   706/block_dev.c     c0144bd7   697/sched.c
 11213   reacqBKL        9  1375/sched.c         c01138b4   696/block_dev.c
 11212  spin_lock        1   547/sched.c         c0111b04   696/block_dev.c
  7552  spin_lock        1   298/buffer.c        c013bb1c   285/buffer.c
  5013        BKL        0  2763/buffer.c        c013fbca   697/sched.c
  4641        BKL        1  1302/inode.c         c016de79   697/sched.c

SunWave1#ksymoops -m /boot/System.map -A " c01138b4 c016b971 c0144d51 
c014250d c014250d c0111b04 c01551f7 c014003c c0111b04 c016b971 e9078837 
c0220517 c0144bd7 c014003c c0144bd7 c01138b4 c0111b04 c013bb1c c013fbca 
c016de79"
ksymoops 2.4.3 on i686 2.4.10-pre12-preempt.  Options used
     -V (default)
     -k /proc/ksyms (default)
     -l /proc/modules (default)
     -o /lib/modules/2.4.10-pre12-preempt/ (default)
     -m /boot/System.map (specified)

Adhoc c01138b4 <preempt_schedule+34/b0>
Adhoc c016b970 <reiserfs_delete_inode+30/110>
Adhoc c0144d50 <blkdev_close+60/1b0>
Adhoc c014250c <kill_super+ac/280>
Adhoc c014250c <kill_super+ac/280>
Adhoc c0111b04 <schedule+34/550>
Adhoc c01551f6 <prune_icache+36/160>
Adhoc c014003c <kupdate+11c/210>
Adhoc c0111b04 <schedule+34/550>
Adhoc c016b970 <reiserfs_delete_inode+30/110>
Adhoc e9078836 <[ipv6]tcp6_get_info+4a6/770>
Adhoc c0220516 <tcp_get_info+4b6/7a0>
Adhoc c0144bd6 <blkdev_put+46/160>
Adhoc c014003c <kupdate+11c/210>
Adhoc c0144bd6 <blkdev_put+46/160>
Adhoc c01138b4 <preempt_schedule+34/b0>
Adhoc c0111b04 <schedule+34/550>
Adhoc c013bb1c <wait_for_locked_buffers+3c/60>
Adhoc c013fbca <sync_old_buffers+2a/130>
Adhoc c016de78 <reiserfs_dirty_inode+58/f0>