Bug 738564 - Very slow disk I/O and high CPU usage
Summary: Very slow disk I/O and high CPU usage
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 16
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-09-15 07:51 UTC by Paul Alesius
Modified: 2011-10-16 07:32 UTC (History)
7 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2011-10-16 07:32:08 UTC


Attachments (Terms of Use)
dmesg (62.94 KB, text/plain)
2011-09-15 07:51 UTC, Paul Alesius
no flags Details
lspci -vvvv (17.59 KB, text/plain)
2011-09-15 07:52 UTC, Paul Alesius
no flags Details
hdparm -I /dev/sda (2.72 KB, text/plain)
2011-09-15 07:53 UTC, Paul Alesius
no flags Details

Description Paul Alesius 2011-09-15 07:51:36 UTC
Created attachment 523309 [details]
dmesg

Description of problem:
Very slow disk I/O. I had an HDD and it was supposed to do at least 40 mb/s but does around 20mb/s, installed an SSD and was seeing ~27mb/s. After a lot of disk activity, for example:
    [root@minibook ~]# dd if=/dev/sda of=file bs=1024000 count=10000
    ^C2311+0 poster in
    2311+0 poster ut
    2366464000 byte (2,4 GB) kopierade, 207,507 s, 11,4 MB/s
or from installing a lot of packages with yum, the kernel process kswapd0 is starting to use near 100% CPU:
    PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
    37 root      20   0     0    0    0 R 92.3  0.0   0:18.55 kswapd0

I've tried with compiling the latest kernel from source (3.1.0 rc6) and the issue is still there. hdparm -t /dev/sda shows:
/dev/sda:
 Timing buffered disk reads:  76 MB in  3.03 seconds =  25.10 MB/sec

I've tried with Ubuntu (Which iirc. uses a 2.6 kernel), the problem isn't there (For exmaple hdparm -t /dev/sda shows a throughput of >260mb/s).

Kernel parameters such as pci=nomsi,nommconf or conf1, did't help.
Tried with both ext4 and btrfs, it was still unusably slow.
Tried with sysctl vm.swappiness=1 and turning off swap, doesn't help to improve the slow I/O and iirc. kswapd0 was still running at near 100%.

I've noticed something odd, after creating a ~100mb file with dd (dd if=/dev/sda of=file bs=1024000 count=100), and copying it, it will copy it very slowly due to this bug, but when copying again and overwriting, it will do this even sower, this seems to happen every time:
----
    [root@minibook ~]# time cp file filecopy2
    real	0m4.048s
    user	0m0.013s
    sys	0m3.774s
    [root@minibook ~]# time cp file filecopy2
    cp: overwrite ”filecopy2”? y
    real	0m15.194s
    user	0m0.010s
    sys	0m13.412s
----


Version-Release number of selected component (if applicable):
kernel 3.1.0-0.rc5.git0.0.fc16.x86_64
kernel 3.1-rc6-vanilla-git

How reproducible:
Always

Steps to Reproduce:
1. Copy a few GB or install a group with yum.
2. Monitor disk throughput.
3. Enter a state of frustration and disappointment.

Actual results:
----
[root@minibook ~]# dd if=/dev/sda of=file bs=1024000 count=100
102400000 byte (102 MB) kopierade, 4,62939 s, 22,1 MB/s
----
[root@minibook ~]# hdparm -t /dev/sda
/dev/sda:
 Timing buffered disk reads:  80 MB in  3.07 seconds =  26.04 MB/sec
----

Expected results:
----
[root@minibook ~]# dd if=/dev/sda of=file bs=1024000 count=100
102400000 byte (102 MB) kopierade, 4,62939 s, 200 MB/s
----
[root@minibook ~]# hdparm -t /dev/sda
/dev/sda:
 Timing buffered disk reads:  80 MB in  3.07 seconds =  270 MB/sec
----

Additional info:

Comment 1 Paul Alesius 2011-09-15 07:52:48 UTC
Created attachment 523311 [details]
lspci -vvvv

Comment 2 Paul Alesius 2011-09-15 07:53:39 UTC
Created attachment 523312 [details]
hdparm -I /dev/sda

Comment 3 Paul Alesius 2011-09-15 09:08:13 UTC
I've tried with older kernels from F15 and F16 and the problem is still there to some extent, but works best with kernel-2.6.40:

kernel  2.6.35.14-96.fc14  x86_64:
    dd if=/dev/sda of=file bs=1024 count=$[1000*1000]
        1024000000 byte (1,0 GB) copied, 65,3817 s, 15,7 MB/s
    dd if=/dev/sda of=/dev/null bs=1024 count=$[1000*1000]
        1024000000 byte (1,0 GB) copied, 7,3404 s, 140 MB/s
    hdparm -t /dev/sda
        /dev/sda:
        Timing buffered disk reads: 364 MB in  3.00 seconds = 121.26 MB/sec

kernel  2.6.40.4-5.fc15  x86_64:
    dd if=/dev/sda of=/dev/null bs=1024 count=$[1000*1000]
        1024000000 byte (1,0 GB) copied, 6,37013 s, 161 MB/s
    dd if=/dev/sda of=file bs=1024 count=$[1000*1000]
        1024000000 byte (1,0 GB) copied, 33,0248 s, 31,0 MB/s
    hdparm -t /dev/sda 
        /dev/sda:
        Timing buffered disk reads: 304 MB in  3.00 seconds = 101.22 MB/sec

Comment 4 Josh Boyer 2011-09-15 14:45:34 UTC
What config did you use when you build 3.1-rc6 yourself?  If you used the config provided by 3.1.0-0.rc5.git0.0.fc16.x86_64 then it has all of the various kernel debugging options enabled, which is known to slow things down greatly in 3.1 for some reason.

You might try the 3.1.0-0.rc6.git0.0.fc16.x86_64 that is being pushed to f16 stable today.  It has the debugging options disabled.

Comment 5 Paul Alesius 2011-09-15 17:05:23 UTC
Josh, I didn't explicitly disable debug options on my custom build of 3.1 rc6.

I just tried with the latest rc6 non -debug kernel (3.1.0-0.rc6.git0.0.fc16.x86_64) as you suggested and it seems to be better but still very slow, I'm not sure if it's supposed to be that way on a machine with little RAM (1GB since the GPU has its own memory), at least kswapd0 doesn't use 100% cpu, but here's the results:

[root@minibook ~]# dd if=/dev/sda of=/dev/null bs=1024 count=$[1000*3000]
  3072000000 byte (3,1 GB) copied, 17,7029 s, 174 MB/s

[root@minibook ~]# dd if=/dev/sda of=somefile bs=1024 count=$[1000*1000]
  1024000000 byte (1,0 GB) copied, 51,0095 s, 20,1 MB/s

[root@minibook noname]# dd if=somefile of=anotherfile
  1024000000 byte (1,0 GB) copied, 93,9416 s, 10,9 MB/s

I also had in rc.local (Not when I posted the bug report):
echo min_power > /sys/class/scsi_host/host0/link_power_management_policy
echo min_power > /sys/class/scsi_host/host1/link_power_management_policy
echo min_power > /sys/class/scsi_host/host2/link_power_management_policy
echo min_power > /sys/class/scsi_host/host3/link_power_management_policy
so I changed it to max_performance and it got a bit better:

[root@minibook ~]# dd if=/dev/sda of=/dev/null bs=1024 count=$[1000*1000]
  1024000000 byte (1,0 GB) kopierade, 5,59175 s, 183 MB/s
[root@minibook ~]# dd if=/dev/sda of=largefile bs=1024 count=$[1000*1000]
  1024000000 byte (1,0 GB) kopierade, 33,9147 s, 30,2 MB/s

I'm not sure if this is the expected behavior with so little RAM, but it seems very slow for an SSD that is supposed to do sequential r280/w280 on a SATA 3Gb/s interface.

Also hdparm shows:
[root@minibook ~]# hdparm -tT /dev/sda
  /dev/sda:
    Timing cached reads:   1364 MB in  2.00 seconds = 682.08 MB/sec
    Timing buffered disk reads: 342 MB in  3.01 seconds = 113.63 MB/sec

And bonnie++, I'm not familiar with its results they're not explained anywhere, but I think it's not supposed to be dependent on RAM:
"bonnie++ -u 1000:1000 -s 2048 -d $(pwd) -m localhost -n 100"
Version  1.96       ------Sequential Output------ --Sequential Input- --Random-
Concurrency   1     -Per Chr- --Block-- -Rewrite- -Per Chr- --Block-- --Seeks--
Machine        Size K/sec %CP K/sec %CP K/sec %CP K/sec %CP K/sec %CP  /sec %CP
localhost        2G    59  99 39726  17 35402  35   548  98 66048  27 871.8 163
Latency               330ms    3159ms    2945ms   31157us   33656us   37836us
Version  1.96       ------Sequential Create------ --------Random Create--------
localhost           -Create-- --Read--- -Delete-- -Create-- --Read--- -Delete--
              files  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP
                100  8322  80 116035  99  8013  96  8484  82 147960  99  7069  94
Latency             15564us    3564us    3066us   23663us     195us   26798us
1.96,1.96,localhost,1,1316103706,2G,,59,99,39726,17,35402,35,548,98,66048,27,871.8,163,100,,,,,8322,80,116035,99,8013,96,8484,82,147960,99,7069,94,330ms,3159ms,2945ms,31157us,33656us,37836us,15564us,3564us,3066us,23663us,195us,26798us

Comment 6 Paul Alesius 2011-09-15 18:12:33 UTC
I just tried on an Ubuntu x64 live cd again which runs kernel 2.6.38 and got very similar results, so I guess this isn\t a bug and is caused by too little RAM?

Comment 7 Paul Alesius 2011-10-16 07:32:08 UTC
Was probably just general netbook slowness. It works well enough now without the kernel debug build.


Note You need to log in before you can comment on or make changes to this bug.