linux-kernel - RE: async I/O seems to be blocking on 2.6.15

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:	Mon, 6 Nov 2006 13:22:12 -0800
From:	"Chen, Kenneth W" <kenneth.w.chen@...el.com>
To:	"'Jens Axboe'" <jens.axboe@...cle.com>,
	"Brent Baccala" <cosine@...esoft.org>
Cc:	<linux-kernel@...r.kernel.org>
Subject: RE: async I/O seems to be blocking on 2.6.15

Jens Axboe wrote on Sunday, November 05, 2006 4:15 AM
> On Fri, Nov 03 2006, Brent Baccala wrote:
> > On Fri, 3 Nov 2006, Jens Axboe wrote:
> > 
> > >Try to time it (visual output of the app is not very telling, and it's
> > >buffered) and then apply some profiling.
> > 
> > OK, a little more info.  I added gettimeofday() calls after each call
> > to io_submit(), put the timevals in an array, and after everything was
> > done computed the difference between each timeval and the program start
> > time, as well as the deltas.  I got this:
> > 
> > 0: 0.080s
> > 1: 0.086s  0.006s
> > 2: 0.102s  0.016s
> > 3: 0.111s  0.008s
> > 4: 0.118s  0.007s
> > 5: 0.134s  0.015s
> > 6: 0.141s  0.006s
> > 7: 0.148s  0.006s
> > 8: 0.158s  0.009s
> > 9: 0.164s  0.006s
> > ...
> > 96: 1.036s  0.007s
> > 97: 1.044s  0.007s
> > 98: 1.147s  0.102s
> > 99: 1.155s  0.008s
> > 
> > 98 appears to be an aberration.  Perhaps three of the times on an
> > average run are around a tenth of a second; all of the others are
> > pretty steady at 7 or 8 microseconds.  So, it's basically linear in
> > its time consumption.
> > 
> > Does 7 microseconds seem a bit excessive for an io_submit (and a
> > gettimeofday)?
> 
> I guess you mean miliseconds, not microseconds. 7 miliseconds seems way
> too long. I repeated your test here, and the 100 submits take 97000
> microseconds here - or 97 miliseconds. So that's a little less than 1
> msec per io_submit. Still pretty big. You can experiment with oprofile
> to profile where the kernel spends its time in that period.


I've tried that myself too and see similar result.  One thing to note is
that I/O being submitted are pretty big at 1MB, so the vector list inside
bio is going to be pretty long and it will take a while to construct that.
Drop the size for each I/O to something like 4KB will significantly reduce
the time.  I haven't done the measurement whether the time to submit I/O
grows linearly with respect to I/O size.  Most likely it will.  If it is
not, then we might have a scaling problem (though I don't believe we have
this problem).

- Ken


-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/