2.5.32 IO performance issues

From: Badari Pulavarty (pbadari@us.ibm.com)
Date: Thu Aug 29 2002 - 13:20:17 EST


Hi,

I am having severe IO performance problems with 2.5.32 (2.5.31 works fine).
I was wondering what caused this.

As you can see, IO rate went from

                384MB/sec with 6% CPU utilization on 2.5.31
                        to
                120MB/sec with 19% CPU utilization on 2.5.32

Any idea ?

Thanks,
Badari

Hardware: 8x 700MHz P-III, 4 Qlogic FC controllers, 40 disks
Test: 40 dds on 40 raw devices (40 disks).

2.5.32 vmstat output:
---------------------

   procs memory swap io system cpu
 r b w swpd free buff cache si so bi bo in cs us sy id
 3 36 0 0 3803972 0 23392 0 0 119962 24 1939 3592 0 18 81
 2 37 0 0 3804144 0 23392 0 0 121024 0 1938 3611 0 19 81
 0 39 0 0 3804776 0 23392 0 0 119834 0 1925 3553 0 19 81
 0 39 0 0 3804172 0 23392 0 0 120128 0 1932 3584 0 19 81
 1 38 0 0 3804680 0 23392 0 0 120346 0 1932 3585 0 19 81
 4 35 0 0 3804536 0 23392 0 0 120806 0 1940 3625 0 18 81
 1 38 1 0 3804212 0 23392 0 0 120512 0 1938 3607 0 19 81
 0 39 0 0 3804592 0 23392 0 0 120282 0 1931 3572 0 19 81
 0 39 0 0 3803944 0 23392 0 0 120755 0 1936 3617 0 19 81

2.5.31 vmstat output:
---------------------
   procs memory swap io system cpu
 r b w swpd free buff cache si so bi bo in cs us sy id
 0 39 0 0 3803732 0 32080 0 0 384141 13 3966 6232 0 5 95
 0 39 0 0 3803700 0 32080 0 0 384230 3 3962 6248 0 6 94
 0 39 0 0 3803696 0 32080 0 0 384256 2 3966 6226 0 5 95
 0 39 0 0 3803696 0 32080 0 0 384179 0 3961 6236 0 5 95
 1 38 0 0 3803684 0 32080 0 0 384230 0 3967 6229 0 5 95
 0 39 0 0 3803680 0 32080 0 0 383782 0 3958 6233 0 6 94
 0 39 0 0 3803680 0 32080 0 0 384154 0 3964 6225 0 5 95
 0 39 0 0 3803676 0 32080 0 0 384077 7 3968 6252 0 5 95

Profile=2 optput for 2.5.32:
---------------------------
# readprofile | sort -nr +2

151712 default_idle 2370.5000
21622 __scsi_end_request 122.8523
  4491 do_softirq 23.3906
  2543 scsi_dispatch_cmd 4.1826
   306 dio_bio_complete 1.7386
  1798 __make_request 1.5608
   756 rmqueue 0.9265
   198 scsi_queue_next_request 0.6513
   100 dio_await_one 0.6250
    25 __wake_up 0.5208
   499 scsi_request_fn 0.4873
    15 scsi_sense_valid 0.4688
    14 page_pool_alloc 0.4375
   167 blk_rq_map_sg 0.4349
   381 schedule 0.4252
   132 __set_page_dirty_buffers 0.3750
    51 generic_unplug_device 0.3542
    17 bio_put 0.3542
    78 scsi_finish_command 0.3482
     5 cap_file_permission 0.3125
   112 mempool_alloc 0.2917
    23 bio_destructor 0.2875
   215 get_user_pages 0.2859
   117 bio_alloc 0.2812
    21 fget 0.2625
    12 dio_prep_bio 0.2500
   194 blk_queue_bounce 0.2497
   165 do_direct_IO 0.2398
    25 cpu_idle 0.2232
     7 _alloc_pages 0.2188
     2 syscall_exit 0.1818
    23 kmem_cache_free 0.1797
    44 __scsi_release_command 0.1654
    13 dio_get_page 0.1625
     5 __get_free_pages 0.1562
     5 fput 0.1562
    32 add_timer 0.1429
    20 blk_run_queues 0.1389
    42 kmem_cache_alloc 0.1382
    23 add_entropy_words 0.1307
    63 __alloc_pages 0.1270
     8 scsi_free_sgtable 0.1250
     8 dio_new_bio 0.1250
     4 slab_pool_alloc 0.1250
    25 scsi_init_cmd_errh 0.1116
    10 mempool_free 0.1111
186646 total 0.1034
     6 __generic_copy_to_user 0.0938
     3 scsi_pool_free 0.0938
     3 scsi_pool_alloc 0.0938
     4 system_call 0.0909
    27 scsi_decide_disposition 0.0844
     9 submit_bio 0.0804
     9 __run_task_queue 0.0804
    24 vfs_read 0.0789
    15 rw_raw_dev 0.0781
     6 bh_action 0.0750
     8 scsi_add_timer 0.0714
    11 generic_file_direct_IO 0.0683
    57 sd_init_command 0.0660
     6 find_vma 0.0625
     6 blkdev_get_blocks 0.0625
     5 max_block 0.0625
     4 dio_await_completion 0.0625
     3 blkdev_direct_IO 0.0625
     2 slab_pool_free 0.0625
    18 vfs_write 0.0592
    10 batch_entropy_process 0.0568
    15 get_more_blocks 0.0551
    31 scsi_softirq 0.0538
     4 dio_bio_submit 0.0500
    35 timer_bh 0.0497
    12 scsi_alloc_sgtable 0.0469
    20 generic_direct_IO 0.0431
     4 find_extend_vma 0.0417
     4 dio_bio_alloc 0.0417
    20 sd_rw_intr 0.0368
     7 tasklet_hi_action 0.0365
     4 dio_bio_reap 0.0357
     9 generic_make_request 0.0352
     2 sys_read 0.0312
     1 __wake_up_locked 0.0312
     1 tqueue_bh 0.0312
    30 scsi_io_completion 0.0280
     4 write_profile 0.0227
     5 scsi_init_io 0.0223
     5 dio_refill_pages 0.0208
     1 in_group_p 0.0208
     1 credit_entropy_store 0.0208
     2 .text.lock.mempool 0.0196
     1 .text.lock.highmem 0.0182
     4 mod_timer 0.0167
     1 atomic_dec_and_lock 0.0161
     1 sys_write 0.0156
     1 free_pages 0.0156
     1 fd_install 0.0156
     1 strncpy_from_user 0.0125
     1 scsi_get_request_dev 0.0125
     2 __d_lookup 0.0089
     1 pfifo_fast_enqueue 0.0089
     1 session_of_pgrp 0.0078
     7 proc_pid_status 0.0071
     2 page_remove_rmap 0.0069
     2 i8042_interrupt 0.0066
     1 scsi_eh_completed_normally 0.0063
     4 number 0.0057
     1 skb_release_data 0.0057
     1 tcp_v4_send_check 0.0052
     1 locks_remove_flock 0.0052
     1 eth_type_trans 0.0052
     1 __find_get_block 0.0048
     1 page_add_rmap 0.0045
     1 __kfree_skb 0.0045
     3 proc_pid_stat 0.0043
     1 bh_lru_install 0.0042
     4 vsnprintf 0.0038
     1 tcp_v4_checksum_init 0.0037
     1 ksoftirqd 0.0037
     1 tcp_poll 0.0030
     1 may_open 0.0026
     1 dentry_open 0.0026
     1 sd_open 0.0024
     5 link_path_walk 0.0023
     2 kstat_read_proc 0.0021
     1 do_anonymous_page 0.0021
     1 tty_write 0.0015
     1 __free_pages_ok 0.0013
     1 ext3_find_entry 0.0012
     2 tulip_interrupt 0.0010

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



This archive was generated by hypermail 2b29 : Sat Aug 31 2002 - 22:00:27 EST