Re: [patch] voluntary-preempt-2.6.9-rc1-bk4-Q5

Lee Revell
2004-09-01T02:30:34Z

On Mon, 2004-08-30 at 05:06, Ingo Molnar wrote:
> i've uploaded -Q5 to:
>
> http://redhat.com/~mingo/voluntary-preempt/voluntary-preempt-2.6.9-rc1-bk4-Q5

Hmm, 385 usec latency triggered by 'lsof /smb' (this is a samba export):

preemption latency trace v1.0.2
-------------------------------
latency: 385 us, entries: 626 (626)
-----------------
| task: lsof/17876, uid:0 nice:0 policy:0 rt_prio:0
-----------------
=> started at: unix_seq_start+0x10/0x50
=> ended at: unix_seq_stop+0xf/0x30
=======>
00000001 0.000ms (+0.000ms): unix_seq_start (seq_read)
00000001 0.000ms (+0.000ms): unix_seq_idx (unix_seq_start)
00000001 0.027ms (+0.027ms): unix_seq_show (seq_read)
00000002 0.028ms (+0.000ms): sock_i_ino (unix_seq_show)
00000002 0.029ms (+0.001ms): seq_printf (unix_seq_show)
00000002 0.030ms (+0.000ms): vsnprintf (seq_printf)
00000002 0.032ms (+0.002ms): number (vsnprintf)
00000002 0.036ms (+0.004ms): skip_atoi (vsnprintf)
00000002 0.037ms (+0.000ms): number (vsnprintf)
00000002 0.038ms (+0.001ms): skip_atoi (vsnprintf)
00000002 0.039ms (+0.000ms): number (vsnprintf)
00000002 0.039ms (+0.000ms): skip_atoi (vsnprintf)
00000002 0.040ms (+0.000ms): number (vsnprintf)
00000002 0.041ms (+0.000ms): skip_atoi (vsnprintf)
00000002 0.041ms (+0.000ms): number (vsnprintf)
00000002 0.042ms (+0.000ms): skip_atoi (vsnprintf)
00000002 0.043ms (+0.000ms): number (vsnprintf)
00000002 0.043ms (+0.000ms): skip_atoi (vsnprintf)
00000002 0.044ms (+0.000ms): number (vsnprintf)
00000002 0.046ms (+0.001ms): seq_putc (unix_seq_show)
00000002 0.047ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.047ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.047ms (+0.000ms): seq_putc (unix_seq_show)

...

00000002 0.374ms (+0.000ms): number (vsnprintf)
00000002 0.375ms (+0.000ms): skip_atoi (vsnprintf)
00000002 0.376ms (+0.000ms): number (vsnprintf)
00000002 0.377ms (+0.001ms): seq_putc (unix_seq_show)
00000002 0.377ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.378ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.378ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.378ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.379ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.379ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.380ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.380ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.380ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.381ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.381ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.381ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.382ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.382ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.382ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.383ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.383ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.383ms (+0.000ms): seq_putc (unix_seq_show)
00000002 0.384ms (+0.000ms): seq_putc (unix_seq_show)
00000001 0.384ms (+0.000ms): preempt_schedule (unix_seq_show)
00000001 0.384ms (+0.000ms): seq_putc (unix_seq_show)
00000001 0.385ms (+0.000ms): unix_seq_stop (seq_read)
00000001 0.386ms (+0.000ms): sub_preempt_count (unix_seq_stop)
00000001 0.386ms (+0.000ms): _mmx_memcpy (check_preempt_timing)
00000001 0.387ms (+0.000ms): kernel_fpu_begin (_mmx_memcpy)

Full trace:

http://krustophenia.net/testresults.php?dataset=2.6.9-rc1-Q5#/var/www/2.6.9-rc1-Q5/trace9.txt

Lee