Skip site navigation (1)Skip section navigation (2)
Date:      Thu, 17 Jan 2002 21:51:04 -0800 (PST)
From:      Kip Macy <kip@eventdriven.org>
To:        freebsd-gnats-submit@FreeBSD.org
Subject:   kern/34016: AIO is 400x slower under -CURRENT
Message-ID:  <200201180551.g0I5p4v89154@freefall.freebsd.org>

next in thread | raw e-mail | index | archive | help

>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




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?200201180551.g0I5p4v89154>