RE: The cause of the "VM" performance problem with 2.4.X

From: Van Maren, Kevin (kevin.vanmaren@unisys.com)
Date: Tue Aug 28 2001 - 12:35:49 EST


Okay, here are some more results with Morton's "2nd" patch,
running 2.4.8,IA64-010815 on 4X IA64 (Lion) with 8GB RAM,
733MHz B3 (4MB) CPUs. 3 Adaptec 39160 channels, each with
8 (18GB) Cheetah drives, create 4 md's using 2 disks from
each channel. Also using Gibbs' 6.2.0 adaptec driver.
I tried to extract the "important" info to keep this message
relatively small. Meant to get this out earlier...

It looks like "getblk" could use some additional optimization.
More info to follow, but even doing one "mkfs" at a time,
the lru_list_lock is held over 82% of the time, mostly by
getblk().

SMP test case: 4 parallel mkfs (each on 6-disk md):
===================================================
  "start"
  mkfs /dev/md0 &
  mkfs /dev/md1 &
  mkfs /dev/md2 &
  mkfs /dev/md3
  "stop"

Abbreiated/stripped kernprof/gprof output:
------------------------------------------

Each sample counts as 0.000976562 seconds.
  % cumulative self self total
 time seconds seconds calls ms/call ms/call name
 39.46 224.65 224.65 cg_record_arc
 16.40 318.00 93.34 6722992 0.01 0.02 getblk
  9.02 369.33 51.33 50673121 0.00 0.00 spin_lock_
  6.67 407.27 37.95 6722669 0.01 0.01 _make_request
  4.51 432.97 25.70 13445261 0.00 0.00 blk_get_queue
  2.61 447.83 14.86 long_copy_user
  2.59 462.56 14.72 mcount
  2.06 474.27 11.71 cpu_idle
  1.35 481.97 7.70 26887936 0.00 0.00 _insert_into_lru_list
  1.23 489.00 7.02 12463048 0.00 0.00 write_lock_
  1.08 495.15 6.15 12463047 0.00 0.00 write_unlock_
  0.94 500.52 5.37 7 767.72 2342.72 _invalidate_buffers
  0.89 505.56 5.04 72518 0.07 0.08 scsi_dispatch_cmd
  0.83 510.26 4.70 216716 0.02 0.65 block_write
  0.77 514.63 4.37 20169809 0.00 0.00 _refile_buffer
  0.74 518.82 4.19 68098 0.06 0.08 scsi_init_io_vc
  0.73 522.96 4.15 58177 0.07 0.34 _scsi_end_request
  0.64 526.60 3.64 25304057 0.00 0.00 _remove_from_lru_list
  0.59 529.97 3.36 718 4.68 4.68 si_swapinfo
  0.56 533.17 3.21 5644224 0.00 0.00 end_buffer_io_sync
  0.40 535.46 2.29 43581 0.05 0.06 ahc_linux_isr
  0.36 537.50 2.04 210123 0.01 0.45 write_some_buffers
  0.35 539.52 2.02 6729267 0.00 0.00 _remove_from_free_list
  0.34 541.46 1.94 13445412 0.00 0.00 balance_dirty_state
[misc "interesting" others]
  0.09 557.35 0.49 116 4.22 41.74 wait_for_buffers
  0.06 560.37 0.33 58177 0.01 0.35 scsi_finish_command
  0.02 565.67 0.14 54 2.57 1655.62 sync_old_buffers
  0.01 567.60 0.04 42 1.00 18.82 page_launder
  0.00 569.24 0.00 43 0.05 146.48 write_unlocked_buffers
  0.00 569.29 0.00 42 0.00 19.44 do_try_to_free_pages
  0.00 569.29 0.00 29 0.00 306.44 sync_buffers
  0.00 569.29 0.00 28 0.00 92.44
wait_for_locked_buffers
  0.00 569.29 0.00 15 0.00 306.48 fsync_dev
  0.00 569.29 0.00 8 0.00 574.65 sys_fsync
  0.00 569.29 0.00 7 0.00 2955.64 blkdev_put

index % time self children called name
[1] 40.5 224.65 0.00 cg_record_arc [1]

[2] 32.3 0.02 179.06 ia64_ret_from_syscall [2]
                0.10 150.24 232733/232733 sys_write [3]

                0.10 150.24 232733/232733 ia64_ret_from_syscall [2]
[3] 27.1 0.10 150.24 232733 sys_write [3]
                4.70 136.37 216716/216716 block_write [4]

                4.70 136.37 216716/216716 sys_write [3]
[4] 25.4 4.70 136.37 216716 block_write [4]
               93.34 26.66 6722748/6722992 getblk [5]
                1.16 11.57 6722748/6723007 mark_buffer_dirty [30]
                0.32 2.90 13445336/13445412 balance_dirty [54]
                0.40 0.00 6722748/6736794 _brelse [112]

                0.00 0.00 32/6722992 block_read [391]
                0.00 0.00 212/6722992 bread [298]
               93.34 26.66 6722748/6722992 block_write [4]
[5] 21.6 93.34 26.66 6722992 getblk [5]
               13.67 0.00 13492508/50673121 spin_lock_ [12]
                3.80 0.00 6747334/12463048 write_lock_ [40]
                3.33 0.00 6747334/12463047 write_unlock_ [42]
                2.02 0.00 6720832/6729267 _remove_from_free_list [69]
                1.93 0.00 6720832/26887936 _insert_into_lru_list [37]
                0.00 0.76 24342/24342 refill_freelist [90]
                0.74 0.00 6720832/6720832 _insert_into_queues [92]
                0.26 0.00 13492508/51086468 spin_unlock_ [78]
                0.16 0.00 6720832/6720832 init_buffer [144]

                0.13 6.15 13845/210123 write_unlocked_buffers [41]
                1.91 87.15 196278/210123 sync_old_buffers [8]
[6] 17.2 2.04 93.30 210123 write_some_buffers [6]
                0.13 88.77 210087/210087 write_locked_buffers [9]
                1.46 0.97 6722667/20169809 _refile_buffer [39]
                1.93 0.00 6722665/26887936 _insert_into_lru_list [37]

[7] 16.5 0.00 91.66 kupdate [7]
                0.14 89.26 54/54 sync_old_buffers [8]
                0.23 2.03 54/116 wait_for_buffers [46]

                0.14 89.26 54/54 kupdate [7]
[8] 16.1 0.14 89.26 54 sync_old_buffers [8]
                1.91 87.15 196278/210123 write_some_buffers [6]
                0.20 0.00 196385/50673121 spin_lock_ [12]

                0.13 88.77 210087/210087 write_some_buffers [6]
[9] 16.0 0.13 88.77 210087 write_locked_buffers [9]
                1.10 87.67 6722665/6722669 submit_bh [10]

                0.00 0.00 4/6722669 ll_rw_block [478]
                1.10 87.67 6722665/6722669 write_locked_buffers [9]
[10] 16.0 1.10 87.67 6722669 submit_bh [10]
                0.97 86.70 6722669/6722669 generic_make_request [11]

                0.97 86.70 6722669/6722669 submit_bh [10]
[11] 15.8 0.97 86.70 6722669 generic_make_request [11]
               37.95 6.98 6722669/6722669 _make_request [13]
               25.70 13.88 13445261/13445261 blk_get_queue [14]
                0.62 1.58 6722592/6722592 md_make_request [67]

                0.11 0.00 108665/50673121 _wake_up [113]
                0.16 0.00 156642/50673121 real_lookup [71]
                0.16 0.00 156651/50673121 d_rehash [143]
                0.16 0.00 156653/50673121 d_alloc [138]
                0.16 0.00 156656/50673121 d_instantiate [142]
                0.16 0.00 156661/50673121 get_empty_inode [136]
                0.20 0.00 196385/50673121 sync_old_buffers [8]
                0.22 0.00 218577/50673121 sys_lseek [38]
                0.37 0.00 360440/50673121 timer_bh [87]
                0.39 0.00 389480/50673121 get_unused_buffer_head
[103]
                0.41 0.00 405522/50673121 d_lookup [105]
                0.81 0.00 800334/50673121 atomic_dec_and_lock [83]
                4.81 0.00 4749700/50673121 put_last_free [45]
                6.81 0.00 6722665/50673121 refile_buffer [34]
                6.81 0.00 6722816/50673121 _make_request [13]
               13.62 0.00 13445261/50673121 blk_get_queue [14]
               13.67 0.00 13492508/50673121 getblk [5]
[12] 9.3 51.33 0.00 50673121 spin_lock_ [12]

               37.95 6.98 6722669/6722669 generic_make_request [11]
[13] 8.1 37.95 6.98 6722669 _make_request [13]
                6.81 0.00 6722816/50673121 spin_lock_ [12]
                0.13 0.00 6722816/51086468 spin_unlock_ [78]
                0.00 0.03 147/147 _get_request_wait [187]

               25.70 13.88 13445261/13445261 generic_make_request [11]
[14] 7.1 25.70 13.88 13445261 blk_get_queue [14]
               13.62 0.00 13445261/50673121 spin_lock_ [12]
                0.26 0.00 13445261/51086468 spin_unlock_ [78]

[15] 4.5 0.05 24.67 ia64_leave_kernel [15]
                0.00 24.28 1479060/1479060 ia64_handle_irq [17]
                0.31 0.05 26208/30536 schedule [111]
                0.00 0.03 3629/3629 ia64_do_page_fault [186]

                0.00 24.28 1492630/1492630 ia64_handle_irq [17]
[16] 4.4 0.00 24.28 1492630 do_IRQ [16]
                0.13 20.78 403703/444995 do_softirq [18]
                0.39 2.89 1492630/1492630 handle_IRQ_event [53]

Lockmeter output (stripped -- holds lock for 1ms+, or 3%+):
-----------------------------------------------------------
System: Linux vanmaren.slc.unisys.com 2.4.8 #23 SMP Fri Aug 24 22:10:04 UTC
2001 ia64
Total counts

All (4) CPUs
Selecting locks that meet ALL of the following:
        utilization : > 1.00%

Start time: Fri Aug 24 22:23:05 2001
End time: Fri Aug 24 22:28:43 2001
Delta Time: 337.74 sec.
Hash table slots in use: 388.
Global read lock slots in use: 245.

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
- - - - - - - - - - - - - - -
SPINLOCKS HOLD WAIT
  UTIL CON MEAN( MAX ) MEAN( MAX )(% CPU) TOTAL NOWAIT SPIN
RJECT NAME

       25.1% 6.1us(5450ms) 59us(5817ms)(65.4%) 60013220 74.9% 25.1%
0.00% *TOTAL*

  3.1% 0.06% 25us( 14ms) 0us 414766 100% 0%
0.06% global_bh_lock
  3.1% 0.06% 25us( 14ms) 0us 414766 100% 0%
0.06% bh_action+0x60

  6.6% 3.9% 1.1us( 201us) 11us( 223us)(0.63%) 20495246 96.1% 3.9%
0% io_request_lock

  3.1% 0.44% 28us(5450ms) 16ms(5817ms)( 2.0%) 381041 99.6% 0.44%
0% kernel_flag
  2.7% 57.1% 1280ms(5450ms) 96us( 183us)(0.00%) 7 42.9% 57.1%
0% blkdev_put+0xf0
 0.26% 0.19% 6.5us(2393us) 33ms(5450ms)(0.65%) 136598 99.8% 0.19%
0% real_lookup+0x220
 0.12% 0.56% 27us(1026us) 28us( 709us)(0.00%) 15118 99.4% 0.56%
0% tty_write+0x4c0
 0.03% 0.38% 29us(5251us) 485ms(5817ms)(0.43%) 3153 99.6% 0.38%
0% vfs_readdir+0x1e0

 87.8% 95.5% 21us(5450ms) 62us(5450ms)(62.1%) 14241646 4.5% 95.5%
0% lru_list_lock
  2.7% 14.3% 1280ms(5450ms) 2.6us( 2.6us)(0.00%) 7 85.7% 14.3%
0% __invalidate_buffers+0x60
 0.03% 100% 4320us( 43ms) 45us( 102us)(0.00%) 20 0% 100%
0% bdflush+0x1d0
 78.1% 96.9% 37us( 12ms) 62us( 256ms)(31.6%) 7143220 3.1% 96.9%
0% getblk+0x60
  1.3% 63.0% 80ms( 261ms) 65us( 436us)(0.00%) 54 37.0% 63.0%
0% kupdate+0x1b0
  4.1% 94.5% 2.0us(2945us) 61us(5450ms)(28.6%) 6725777 5.5% 94.5%
0% refile_buffer+0x50
  1.0% 95.9% 18us(6871us) 66us( 12ms)(0.92%) 195148 4.1% 95.9%
0% sync_old_buffers+0x120
 0.47% 85.3% 9.8us(1407us) 81us( 26ms)(0.83%) 162013 14.7% 85.3%
0% try_to_free_buffers+0xb0
 0.03% 8.7% 1102us( 55ms) 52ms( 199ms)(0.03%) 92 91.3% 8.7%
0% wait_for_locked_buffers+0x60
 0.19% 27.6% 42us( 20ms) 324us( 253ms)(0.10%) 14915 72.4% 27.6%
0% write_unlocked_buffers+0x60

  2.1% 9.1% 1.0us(3507us) 11us( 10ms)(0.51%) 6745773 90.9% 9.1%
0% unused_list_lock
  2.0% 9.1% 1.0us(3507us) 11us( 10ms)(0.50%) 6720952 90.9% 9.1%
0% get_unused_buffer_head+0x50

  1.0% 0.29% 0.5us(1386us) 2.0us( 712us)(0.00%) 7140899 99.7% 0.29%
0% getblk+0x2d0

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
- - - - - - - - - - - - - - - - - - - -
RWLOCK READS HOLD MAX RDR BUSY PERIOD WAIT
  UTIL CON MEAN RDRS MEAN( MAX ) MEAN( MAX )( %CPU) TOTAL
NOWAIT SPIN NAME

       0.00% 20us( 45us)(0.00%) 847741
100% 0.00% *TOTAL*

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
- - - - - - - - - - - - - - - - - - - - - - - -
RWLOCK WRITES HOLD WAIT (ALL) WAIT (WW)
  UTIL CON MEAN( MAX ) MEAN( MAX )( %CPU) MEAN( MAX ) TOTAL
NOWAIT SPIN( WW ) NAME

       0.00% 18us( 12ms) 6.1us( 52us)(0.00%) 1.9us( 2.3us) 12941611
100% 0.00%(0.00%) *TOTAL*

 69.2% 0.00% 19us( 12ms) 11us( 52us)(0.00%) 1.9us( 2.3us) 12058253
100% 0.00%(0.00%) hash_table_lock
  1.8% 0% 1.3us( 49us) 0us 0us 4753020
100% 0%( 0%) __invalidate_buffers+0x270
 67.2% 0.00% 32us( 12ms) 11us( 52us)(0.00%) 1.9us( 2.3us) 7143220
100% 0.00%(0.00%) getblk+0x80
 0.24% 0% 4.9us(1402us) 0us 0us 162013
100% 0%( 0%) try_to_free_buffers+0xd0

=========================================================
Single CPU/FS test case: 1 mkfs (md of the 4 md's above):
Note that only 16% is "idle" on a 4X.
=========================================================

Kgprof:
-------
Each sample counts as 0.000976562 seconds.
  % cumulative self self total
 time seconds seconds calls ms/call ms/call name
 28.88 158.93 158.93 cg_record_arc
 15.89 246.38 87.44 cpu_idle
 14.82 327.95 81.58 6723015 0.01 0.02 getblk
 14.42 407.30 79.35 59278971 0.00 0.00 spin_lock_
  5.23 436.10 28.80 20168512 0.00 0.00 blk_get_queue
  4.60 461.44 25.34 6722884 0.00 0.01 _make_request
  2.56 475.53 14.08 mcount
  2.21 487.71 12.18 long_copy_user
  0.91 492.72 5.01 87690 0.06 0.06 scsi_dispatch_cmd
  0.78 496.99 4.27 83855 0.05 0.27 _scsi_end_request
  0.75 501.11 4.12 87690 0.05 0.08 scsi_init_io_vc
  0.68 504.85 3.74 2 1870.61 7179.64 _invalidate_buffers
  0.65 508.43 3.57 6398252 0.00 0.00 end_buffer_io_sync
  0.51 511.25 2.82 56707 0.05 0.06 ahc_linux_isr
  0.49 513.97 2.72 666 4.09 4.09 si_swapinfo
  0.44 516.40 2.43 82692 0.03 0.03 scsi_malloc
  0.32 518.17 1.78 26887713 0.00 0.00 _insert_into_lru_list
[other interesting points]
  0.24 522.20 1.33 216677 0.01 0.55 block_write
  0.21 527.01 1.16 87102 0.01 0.16 scsi_request_fn
  0.10 537.63 0.54 47 11.55 31.51 page_launder
  0.04 544.66 0.24 98 2.43 15.73 wait_for_buffers
  0.01 548.49 0.05 47 0.98 1887.26 sync_old_buffers
  0.00 550.42 0.00 47 0.00 32.21 do_try_to_free_pages
  0.00 550.42 0.00 12 0.00 462.33 write_unlocked_buffers
  0.00 550.42 0.00 8 0.00 793.75 sync_buffers
  0.00 550.42 0.00 8 0.00 100.26
wait_for_locked_buffers
  0.00 550.42 0.00 4 0.00 793.75 fsync_dev
  0.00 550.42 0.00 2 0.00 8767.16 blkdev_put
  0.00 550.42 0.00 2 0.00 1587.54 sys_fsync

[1] 29.6 158.93 0.00 cg_record_arc [1]

[2] 28.3 0.03 152.01 ia64_ret_from_syscall [2]
                0.09 127.90 231867/231867 sys_write [3]
                0.03 7.21 66165/66165 sys_read [37]
                0.07 6.84 218393/218393 sys_lseek [38]

                0.09 127.90 231867/231867 ia64_ret_from_syscall [2]
[3] 23.9 0.09 127.90 231867 sys_write [3]
                1.33 118.33 216677/216677 block_write [4]

                1.33 118.33 216677/216677 sys_write [3]
[4] 22.3 1.33 118.33 216677 block_write [4]
               81.58 22.81 6722853/6723015 getblk [5]
                0.64 10.42 6722853/6723043 mark_buffer_dirty [31]

                0.00 0.00 8/6723015 block_read [414]
                0.00 0.00 154/6723015 bread [320]
               81.58 22.81 6722853/6723015 block_write [4]
[5] 19.5 81.58 22.81 6723015 getblk [5]
               18.08 0.00 13509844/59278971 spin_lock_ [13]
                0.00 1.17 32955/32955 refill_freelist [76]
                0.87 0.00 6720919/6720919 _insert_into_queues [84]
                0.76 0.00 6720919/6720919 _remove_from_free_list [89]
                0.58 0.00 6755970/14043341 write_unlock_ [75]
                0.47 0.00 6755970/14043341 write_lock_ [83]
                0.44 0.00 6720919/26887713 _insert_into_lru_list [64]
                0.25 0.00 13509844/59693888 spin_unlock_ [78]
                0.18 0.00 6720919/6720919 init_buffer [142]

                0.01 5.52 12374/210102 write_unlocked_buffers [42]
                0.20 88.19 197728/210102 sync_old_buffers [11]
[6] 17.5 0.21 93.71 210102 write_some_buffers [6]
                0.04 92.58 210092/210092 write_locked_buffers [7]
                0.36 0.28 6722899/22499809 _refile_buffer [59]
                0.44 0.00 6722883/26887713 _insert_into_lru_list [64]

                0.04 92.58 210092/210092 write_some_buffers [6]
[7] 17.3 0.04 92.58 210092 write_locked_buffers [7]
                0.30 92.28 6722883/6722884 submit_bh [8]

                0.00 0.00 1/6722884 ll_rw_block [507]
                0.30 92.28 6722883/6722884 write_locked_buffers [7]
[8] 17.3 0.30 92.28 6722884 submit_bh [8]
                0.25 92.02 6722884/6722884 generic_make_request [9]

                0.25 92.02 6722884/6722884 submit_bh [8]
[9] 17.2 0.25 92.02 6722884 generic_make_request [9]
               28.80 27.38 20168512/20168512 blk_get_queue [14]
               25.34 9.16 6722884/6722884 _make_request [15]
                0.33 1.01 13445628/13445628 md_make_request [70]

[10] 16.7 0.00 89.44 kupdate [10]
                0.05 88.66 47/47 sync_old_buffers [11]
                0.11 0.62 47/98 wait_for_buffers [65]

                0.05 88.66 47/47 kupdate [10]
[11] 16.5 0.05 88.66 47 sync_old_buffers [11]
                0.20 88.19 197728/210102 write_some_buffers [6]
                0.26 0.00 197821/59278971 spin_lock_ [13]
                0.00 0.00 47/47 sync_unlocked_inodes [295]
                0.00 0.00 47/51 sync_supers [424]
                0.00 0.00 187/59693888 spin_unlock_ [78]

[12] 16.3 87.44 0.09 cpu_idle [12]
                0.06 0.03 10282/31233 schedule [129]

                0.15 0.00 109352/59278971 ahc_linux_isr [50]
                0.15 0.00 113900/59278971 do_IRQ [33]
                0.18 0.00 136509/59278971 real_lookup [63]
                0.18 0.00 136518/59278971 d_alloc [132]
                0.18 0.00 136518/59278971 d_rehash [141]
                0.18 0.00 136521/59278971 d_instantiate [140]
                0.18 0.00 136521/59278971 get_empty_inode [133]
                0.19 0.00 139538/59278971 _wake_up [107]
                0.23 0.00 173973/59278971 try_to_free_buffers [91]
                0.26 0.00 197821/59278971 sync_old_buffers [11]
                0.29 0.00 218393/59278971 sys_lseek [38]
                0.47 0.00 353459/59278971 d_lookup [101]
                0.47 0.00 354202/59278971 timer_bh [99]
                0.71 0.00 527288/59278971 get_unused_buffer_head
[87]
                0.93 0.00 696032/59278971 atomic_dec_and_lock [82]
                8.45 0.00 6310839/59278971 put_last_free [36]
                9.00 0.00 6722880/59278971 refile_buffer [35]
                9.00 0.00 6723070/59278971 _make_request [15]
               18.08 0.00 13509844/59278971 getblk [5]
               27.00 0.00 20168512/59278971 blk_get_queue [14]
[13] 14.8 79.35 0.00 59278971 spin_lock_ [13]

               28.80 27.38 20168512/20168512 generic_make_request [9]
[14] 10.5 28.80 27.38 20168512 blk_get_queue [14]
               27.00 0.00 20168512/59278971 spin_lock_ [13]
                0.38 0.00 20168512/59693888 spin_unlock_ [78]

Lockstat:
---------
System: Linux vanmaren.slc.unisys.com 2.4.8 #23 SMP Fri Aug 24 22:10:04 UTC
2001 ia64
Total counts

All (4) CPUs
Selecting locks that meet ALL of the following:
        utilization : > 1.00%

Start time: Fri Aug 24 22:43:51 2001
End time: Fri Aug 24 22:48:34 2001
Delta Time: 283.01 sec.
Hash table slots in use: 297.
Global read lock slots in use: 214.

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
- - - - - - - - - - - - - - -
SPINLOCKS HOLD WAIT
  UTIL CON MEAN( MAX ) MEAN( MAX )(% CPU) TOTAL NOWAIT SPIN
RJECT NAME

        1.1% 4.6us( 582ms) 47us(5781ms)( 2.7%) 59050695 98.9% 1.1%
0.02% *TOTAL*

  1.0% 5.1% 18us( 111us) 35us( 576us)(0.03%) 163560 94.9% 5.1%
0% allocator_request_lock

  1.4% 0.01% 0.3us( 7.2us) 15us( 41us)(0.00%) 13108126 100% 0.01%
0% free_list+0x18

  3.8% 2.3% 27us(7193us) 0us 400694 97.7% 0%
2.3% global_bh_lock
  3.8% 2.3% 27us(7193us) 0us 400694 97.7% 0%
2.3% bh_action+0x60

  5.5% 0.78% 0.6us( 96us) 3.4us( 95us)(0.06%) 27316523 99.2% 0.78%
0% io_request_lock
  3.6% 0.27% 1.5us( 42us) 3.9us( 45us)(0.01%) 6723632 99.7% 0.27%
0% __make_request+0x290

 82.4% 3.1% 17us( 582ms) 32us( 582ms)( 1.2%) 13719319 96.9% 3.1%
0% lru_list_lock
 0.04% 0% 59ms( 117ms) 0us 2 100% 0%
0% __invalidate_buffers+0x60
 78.3% 0.26% 33us( 97us) 89us( 296ms)(0.14%) 6746687 99.7% 0.26%
0% getblk+0x60
  1.5% 18.2% 99ms( 582ms) 5.4us( 29us)(0.00%) 44 81.8% 18.2%
0% kupdate+0x1b0
 0.01% 0% 603us( 15ms) 0us 48 100% 0%
0% wait_for_locked_buffers+0x60

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
- - - - - - - - - - - - - - - - - - - -
RWLOCK READS HOLD MAX RDR BUSY PERIOD WAIT
  UTIL CON MEAN RDRS MEAN( MAX ) MEAN( MAX )( %CPU) TOTAL
NOWAIT SPIN NAME

       0.00% 1.2us( 1.2us)(0.00%) 766789
100% 0.00% *TOTAL*

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
- - - - - - - - - - - - - - - - - - - - - - - -
RWLOCK WRITES HOLD WAIT (ALL) WAIT (WW)
  UTIL CON MEAN( MAX ) MEAN( MAX )( %CPU) MEAN( MAX ) TOTAL
NOWAIT SPIN( WW ) NAME

          0% 16us( 97us) 0us 0us 13859543
100% 0%( 0%) *TOTAL*

 79.8% 0% 17us( 97us) 0us 0us 13125889
100% 0%( 0%) hash_table_lock
  2.6% 0% 1.2us( 5.4us) 0us 0us 6339799
100% 0%( 0%) __invalidate_buffers+0x270
 76.9% 0% 32us( 97us) 0us 0us 6746687
100% 0%( 0%) getblk+0x80
-
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 : Fri Aug 31 2001 - 21:00:30 EST