linux-kernel - Very slow SYS_io

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-next>] [day] [month] [year] [list]

Message-ID: <27245a6a-a827-2662-215c-05ccdff65768@gblabs.co.uk>
Date:   Fri, 20 Jul 2018 20:39:42 +0100
From:   Alex Richman <alex.r@...abs.co.uk>
To:     linux-kernel@...r.kernel.org, linux-fsdevel@...r.kernel.org
Subject: Very slow SYS_io_destroy()

Hi,

I'm seeing some weirdness with AIO, specifically SYS_io_destroy() is 
taking upwards of ~100000 microseconds (~100 miliseconds) per call.
How long is that call expected to take?  I can see from the source that 
it's waiting e.g. for requests to finish but at the time of my call all 
requests are already finished (and SYS_io_getevent()'d)...

Here's some logs for example (<annotations for clarity>):
1532115053.520016 > hook_1(1073741824, 94766015790162, 14, 100, 
139919450371008, 15) -> 0x7ffe9e505770
<3 IOCBs prepared, CMD_PWRITEV IOVs, 1 IOV per write, 14 bytes per write>
1532115053.520035 = {prep(0 - fd: 4, o: 0, b: 0x7ffe9e504658, n: 1, p: 
0, fl: 0)}
1532115053.520037 = {prep(1 - fd: 5, o: 0, b: 0x7ffe9e504658, n: 1, p: 
0, fl: 0)}
1532115053.520038 = {prep(2 - fd: 6, o: 0, b: 0x7ffe9e504658, n: 1, p: 
0, fl: 0)}
<IOCBs submitted>
1532115053.520415 = {submit(-1978707968, 3) -> 3}
<io_events retreived>
1532115053.520417 = {done(0 - r: 14)}
1532115053.520418 = {done(1 - r: 14)}
1532115053.520419 = {done(2 - r: 14)}
1532115053.520420 = {complete(3) -> 14}
<io_cxt destroyed>
1532115053.639594 = {destroy(-1978707968) -> 0}
1532115053.639601 = (0x7ffe9e505770 = 0)

Between the complete(3) line and destroy(-etc) line only 
SYS_io_destroy() is being called.  It's the only possible source of that 
lost ~100 miliseconds...

Any ideas?

Many thanks,
- Alex.

-- 
Alex Richman
alex.r@...abs.co.uk
Engineering
Tel:+44 (0)118 455 5000
www.gblabs.com