From owner-freebsd-bugs Thu Jan 17 22: 0:33 2002 Delivered-To: freebsd-bugs@hub.freebsd.org Received: from freefall.freebsd.org (freefall.FreeBSD.org [216.136.204.21]) by hub.freebsd.org (Postfix) with ESMTP id E199337B422 for ; Thu, 17 Jan 2002 22:00:00 -0800 (PST) Received: (from gnats@localhost) by freefall.freebsd.org (8.11.6/8.11.6) id g0I600u90300; Thu, 17 Jan 2002 22:00:00 -0800 (PST) (envelope-from gnats) Received: from freefall.freebsd.org (freefall.FreeBSD.org [216.136.204.21]) by hub.freebsd.org (Postfix) with ESMTP id D1A3437B405 for ; Thu, 17 Jan 2002 21:51:04 -0800 (PST) Received: (from nobody@localhost) by freefall.freebsd.org (8.11.6/8.11.6) id g0I5p4v89154; Thu, 17 Jan 2002 21:51:04 -0800 (PST) (envelope-from nobody) Message-Id: <200201180551.g0I5p4v89154@freefall.freebsd.org> Date: Thu, 17 Jan 2002 21:51:04 -0800 (PST) From: Kip Macy To: freebsd-gnats-submit@FreeBSD.org X-Send-Pr-Version: www-1.0 Subject: kern/34016: AIO is 400x slower under -CURRENT Sender: owner-freebsd-bugs@FreeBSD.ORG Precedence: bulk List-ID: List-Archive: (Web Archive) List-Help: (List Instructions) List-Subscribe: List-Unsubscribe: X-Loop: FreeBSD.org >Number: 34016 >Category: kern >Synopsis: AIO is 400x slower under -CURRENT >Confidential: no >Severity: serious >Priority: medium >Responsible: freebsd-bugs >State: open >Quarter: >Keywords: >Date-Required: >Class: sw-bug >Submitter-Id: current-users >Arrival-Date: Thu Jan 17 22:00:00 PST 2002 >Closed-Date: >Last-Modified: >Originator: Kip Macy >Release: -CURRENT >Organization: Extended Solutions >Environment: FreeBSD weizen.extendedsolutions.com 5.0-20020106-CURRENT FreeBSD 5.0-20020106-CURRENT #0: Thu Jan 17 15:36:56 PST 2002 root@weizen.extendedsolutions.com:/usr/src/sys/i386/compile/HADES_UP i386 >Description: I wrote a simple program that uses the three different completion mechanisms (polling with aio_error, polling with kevent, and using SIGIO) to fill up a file by writing 8kb at a time to the file and then reading 8kb at a time from the file. The lower the average latency, the more frequently it can send off a new request and the more quickly it can complete. It can be found at: http://www.eventdriven.org/aio_lat_test.tgz Don't try using the aiotest_sigio (on FreeBSD), the siginfo_t doesn't get filled. Yet another PR that I have to file. Here are the results (in ms): 10 32MB files 4-way Sun server over NFS Memory: 4096M real, 924M free, 768M swap in use, 7234M swap free > uname -a SunOS orbit 5.8 Generic_108528-11 sun4u sparc SUNW,Ultra-Enterprise > ./aiotest_sigio write sk_msecs: 112350 max_latency: 560 reads sk_msecs: 119670 max_latency: 780 > ./aiotest_aio_error write sk_msecs: 45570 max_latency: 240 reads sk_msecs: 48280 max_latency: 630 > ./aiotest_sigio write sk_msecs: 117260 max_latency: 410 reads sk_msecs: 124100 max_latency: 600 > ./aiotest_aio_error write sk_msecs: 45050 max_latency: 780 reads sk_msecs: 46550 max_latency: 1530 10 32MB files 600Mhz Laptop local disk UDMA33 Mem: 68M Active, 134M Inact, 30M Wired, 15M Cache, 35M Buf, 656K Free kmacy@netherworld [15:20][~/src/bugs] uname -a FreeBSD netherworld.eventdriven.org 4.5-RC FreeBSD 4.5-RC #1: Wed Jan 16 21:30:55 PST 2002 root@netherworld.e ventdriven.org:/usr/src/sys/compile/NETHERWORLD i386 kmacy@netherworld [15:08][~/src/bugs/aio] ./aiotest_aio_error write sk_msecs: 72890 max_latency: 930 reads sk_msecs: 56830 max_latency: 930 kmacy@netherworld [15:11][~/src/bugs/aio] ./aiotest_kevent write sk_msecs: 71300 max_latency: 1380 reads sk_msecs: 54500 max_latency: 1380 kmacy@netherworld [15:14][~/src/bugs/aio] ./aiotest_aio_error write sk_msecs: 73970 max_latency: 990 reads sk_msecs: 56790 max_latency: 990 kmacy@netherworld [15:17][~/src/bugs/aio] ./aiotest_kevent write sk_msecs: 73620 max_latency: 980 reads sk_msecs: 59620 max_latency: 1860 2-way 1.0GHZ FreeBSD weizen.extendedsolutions.com 5.0-20020106-CURRENT FreeBSD 5.0-20020106-CURRENT #3: Thu Jan 10 18:58:36 PS T 2002 root@weizen.extendedsolutions.com:/usr/src/sys/i386/compile/HADES i386 Mem: 11M Active, 188M Inact, 111M Wired, 1760K Cache, 111M Buf, 691M Free (~420x slower) (~420x slower) 10 1MB files local disk (UDMA33) > aiotest_aio_error write sk_msecs: 959540 max_latency: 29960 reads sk_msecs: 959970 max_latency: 29960 Same machine compiled UP: > aiotest_aio_error write sk_msecs: 810010 max_latency: 29960 reads sk_msecs: 779950 max_latency: 29960 > uname -a FreeBSD weizen.extendedsolutions.com 5.0-20020106-CURRENT FreeBSD 5.0-20020106-CURRENT #0: Thu Jan 17 15:36:56 PS T 2002 root@weizen.extendedsolutions.com:/usr/src/sys/i386/compile/HADES_UP i386 I wrote a simple program that uses the three different completion mechanisms (polling with aio_error, polling with kevent, and using SIGIO) to fill up a file by writing 8kb at a time to the file and then reading 8kb at a time from the file. The lower the average latency, the more frequently it can send off a new request. It can be found at: http://www.eventdriven.org/aio_lat_test.tgz Don't try using the aiotest_sigio (on FreeBSD), the siginfo_t doesn't get filled. Yet another PR that I have to file. Here are the results (in ms): 10 32MB files 4-way Sun server over NFS Memory: 4096M real, 924M free, 768M swap in use, 7234M swap free > uname -a SunOS orbit 5.8 Generic_108528-11 sun4u sparc SUNW,Ultra-Enterprise > ./aiotest_sigio write sk_msecs: 112350 max_latency: 560 reads sk_msecs: 119670 max_latency: 780 > ./aiotest_aio_error write sk_msecs: 45570 max_latency: 240 reads sk_msecs: 48280 max_latency: 630 > ./aiotest_sigio write sk_msecs: 117260 max_latency: 410 reads sk_msecs: 124100 max_latency: 600 > ./aiotest_aio_error write sk_msecs: 45050 max_latency: 780 reads sk_msecs: 46550 max_latency: 1530 10 32MB files 600Mhz Laptop local disk UDMA33 Mem: 68M Active, 134M Inact, 30M Wired, 15M Cache, 35M Buf, 656K Free kmacy@netherworld [15:20][~/src/bugs] uname -a FreeBSD netherworld.eventdriven.org 4.5-RC FreeBSD 4.5-RC #1: Wed Jan 16 21:30:55 PST 2002 root@netherworld.e ventdriven.org:/usr/src/sys/compile/NETHERWORLD i386 kmacy@netherworld [15:08][~/src/bugs/aio] ./aiotest_aio_error write sk_msecs: 72890 max_latency: 930 reads sk_msecs: 56830 max_latency: 930 kmacy@netherworld [15:11][~/src/bugs/aio] ./aiotest_kevent write sk_msecs: 71300 max_latency: 1380 reads sk_msecs: 54500 max_latency: 1380 kmacy@netherworld [15:14][~/src/bugs/aio] ./aiotest_aio_error write sk_msecs: 73970 max_latency: 990 reads sk_msecs: 56790 max_latency: 990 kmacy@netherworld [15:17][~/src/bugs/aio] ./aiotest_kevent write sk_msecs: 73620 max_latency: 980 reads sk_msecs: 59620 max_latency: 1860 2-way 1.0GHZ FreeBSD weizen.extendedsolutions.com 5.0-20020106-CURRENT FreeBSD 5.0-20020106-CURRENT #3: Thu Jan 10 18:58:36 PS T 2002 root@weizen.extendedsolutions.com:/usr/src/sys/i386/compile/HADES i386 Mem: 11M Active, 188M Inact, 111M Wired, 1760K Cache, 111M Buf, 691M Free (~420x slower) (~420x slower) 10 1MB files local disk (UDMA33) > aiotest_aio_error write sk_msecs: 959540 max_latency: 29960 reads sk_msecs: 959970 max_latency: 29960 Same machine compiled UP: > aiotest_aio_error write sk_msecs: 810010 max_latency: 29960 reads sk_msecs: 779950 max_latency: 29960 > uname -a FreeBSD weizen.extendedsolutions.com 5.0-20020106-CURRENT FreeBSD 5.0-20020106-CURRENT #0: Thu Jan 17 15:36:56 PS T 2002 root@weizen.extendedsolutions.com:/usr/src/sys/i386/compile/HADES_UP i386 >How-To-Repeat: run aiotest_aio_error and aiotest_kevent by compiling the source from: http://www.eventdriven.org/aio_lat_test.tgz >Fix: >Release-Note: >Audit-Trail: >Unformatted: To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-bugs" in the body of the message