lkml.org 
[lkml]   [2006]   [Jul]   [10]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: splice/tee bugs?
On Mon, Jul 10 2006, Jens Axboe wrote:
> On Mon, Jul 10 2006, Michael Kerrisk wrote:
> > > > One slight strangeness. Most of the time, the
> > > > "find . | ktee r | wc" command line takes about 0.1 seconds to
> > > > execute, but about 1 time in 5 on my x86 system, it takes about
> > > > 1.5 to 2 seconds to execute. Any ideas about what's happening
> > > > there?
> > >
> > > That is pretty odd. Any chance you can do a quick sysrq-t and see where
> > > find/ktee/wc is stuck when this happens? You should not be seeing that,
> > > naturally, I'll see if I can reproduce that here. How much data does
> > > find . return in your example?
> >
> > See the start of this message.
> >
> > One sysrq-t output output below.
> >
> > Cheers,
> >
> > Michael
> >
> >
> > find D B9099C00 0 14170 4167 14171 (NOTLB)
> > ca279d04 00118054 00000008 b9099c00 003d0ca2 e7b0b9f8 00000009 d307f688
> > d307f580 c0459dc0 c1507620 b9099c00 003d0ca2 00000000 00000000 00118054
> > 00000001 00001000 c015010e e647f5ac e647f5b8 00000046 00000000 00000000
> > Call Trace:
> > <c015010e> __getblk+0x1d/0x225
> > <c03e1e7c> io_schedule+0x26/0x30
> > <c0150874> sync_buffer+0x37/0x3a
> > <c03e25fd> __wait_on_bit+0x33/0x59
> > <c015083d> sync_buffer+0x0/0x3a
> > <c03e2695> out_of_line_wait_on_bit+0x72/0x7a
> > <c015083d> sync_buffer+0x0/0x3a
> > <c0127dd5> wake_bit_function+0x0/0x34
> > <c019e39b> search_by_key+0x133/0xd91
> > <c0110a1c> do_page_fault+0x0/0x532
> > <c0189e2d> search_by_entry_key+0x20/0x22f
> > <c015dc76> filldir64+0x8e/0xc3
> > <c019e214> pathrelse+0x1b/0x2f
> > <c019388c> reiserfs_readdir+0x3e3/0x3fb
> > <c0193895> reiserfs_readdir+0x3ec/0x3fb
> > <c018d6e5> reiserfs_update_sd_size+0x67/0x24c
> > <c01a55c9> journal_begin+0x9c/0xdc
> > <c0196cb0> reiserfs_dirty_inode+0x5a/0x76
> > <c016bacc> __mark_inode_dirty+0x2d/0x15e
> > <c015dd9a> vfs_readdir+0x58/0x6f
> > <c015de14> sys_getdents64+0x63/0xa8
> > <c015dbe8> filldir64+0x0/0xc3
> > <c010287f> syscall_call+0x7/0xb
>
> So it's find being stuck, this doesn't look tee/splice related at all.
> Can you reproduce the same thing just by doing the find . > /dev/null?

I think you found an unrelated bug, I can reproduce the same thing with
just find . > /dev/null here:

centera:/data1 # time find . > /dev/null

real 0m0.206s
user 0m0.009s
sys 0m0.196s
centera:/data1 # time find . > /dev/null

real 0m0.205s
user 0m0.008s
sys 0m0.198s
centera:/data1 # time find . > /dev/null

real 0m0.205s
user 0m0.012s
sys 0m0.194s
centera:/data1 # time find . > /dev/null

real 0m0.836s
user 0m0.011s
sys 0m0.194s

It's pretty close to 0.2 seconds most of the time, sometimes find takes
more than 1 second to complete though. Even nice'ing find to -20
reproduces the same thing.

--
Jens Axboe

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

\
 
 \ /
  Last update: 2006-07-10 10:51    [W:0.081 / U:0.508 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site