* kernbench on 512p
@ 2004-08-19 16:16 Jesse Barnes
2004-08-19 16:22 ` William Lee Irwin III
` (3 more replies)
0 siblings, 4 replies; 35+ messages in thread
From: Jesse Barnes @ 2004-08-19 16:16 UTC (permalink / raw)
To: linux-kernel
I set out to benchmark the page cache round robin stuff I posted earlier to
see whether round robining across 256 nodes would really hurt kernbench
performance. What I found was that things aren't scaling well enough to make
reasonable measurements.
time user system %cpu ctx sleeps
2.6.8.1-mm1+nodespan 108.622 1588 10536 11158 31193 397966
2.6.8.1-mm1+ns+rr 105.614 1163 8631 9302 27774 420888
2.6.8.1-mm1+nodespan is just 2.6.8.1-mm1 with my last node-span patch applied.
2.6.8.1-mm1+ns+rr is that plus the page cache round robin patch I posted
recently. I just extracted the 'optimal run' average for each of the above
lines.
Here's the kernel profile. It would be nice if the patch to show which lock
is contended got included. I think it was discussed awhile back, but I don't
have one against the newly merged profiling code.
[root@ascender root]# readprofile -m System.map | sort -nr | head -30
208218076 total 30.1677
90036167 ia64_pal_call_static 468938.3698
88140492 default_idle 229532.5312
10312592 ia64_save_scratch_fpregs 161134.2500
10306777 ia64_load_scratch_fpregs 161043.3906
8723555 ia64_spinlock_contention 90870.3646
121385 rcu_check_quiescent_state 316.1068
40464 file_move 180.6429
32374 file_kill 144.5268
25316 atomic_dec_and_lock 98.8906
24814 clear_page 155.0875
17709 file_ra_state_init 110.6813
17603 clear_page_tables 13.4169
16822 copy_page 65.7109
16683 del_timer_sync 32.5840
15098 zap_pte_range 7.8635
15076 __d_lookup 16.8259
13275 find_get_page 31.9111
12898 __copy_user 5.5214
10472 finish_task_switch 36.3611
10037 ia64_pfn_valid 52.2760
8610 get_zone_counts 22.4219
7905 current_kernel_time 41.1719
7155 __down_trylock 22.3594
7063 _pagebuf_find 4.9049
6995 xfs_ilock 13.6621
6965 tasklet_action 8.3714
6494 free_page_and_swap_cache 28.9911
5652 nr_free_pages 22.0781
5555 xfs_trans_push_ail 3.6165
This is a 64p profile only. If I set the prof_cpu_mask to include all 512
CPUs, the system livelocks. I reset the counter right after the warmup run,
partly through the half load run, and collected it after a few runs were
complete.
Thanks,
Jesse
^ permalink raw reply [flat|nested] 35+ messages in thread* Re: kernbench on 512p 2004-08-19 16:16 kernbench on 512p Jesse Barnes @ 2004-08-19 16:22 ` William Lee Irwin III 2004-08-19 16:29 ` David Mosberger ` (2 subsequent siblings) 3 siblings, 0 replies; 35+ messages in thread From: William Lee Irwin III @ 2004-08-19 16:22 UTC (permalink / raw) To: Jesse Barnes; +Cc: linux-kernel On Thu, Aug 19, 2004 at 12:16:33PM -0400, Jesse Barnes wrote: > Here's the kernel profile. It would be nice if the patch to show which lock > is contended got included. I think it was discussed awhile back, but I don't > have one against the newly merged profiling code. > [root@ascender root]# readprofile -m System.map | sort -nr | head -30 > 208218076 total 30.1677 > 90036167 ia64_pal_call_static 468938.3698 > 88140492 default_idle 229532.5312 > 10312592 ia64_save_scratch_fpregs 161134.2500 > 10306777 ia64_load_scratch_fpregs 161043.3906 > 8723555 ia64_spinlock_contention 90870.3646 > 121385 rcu_check_quiescent_state 316.1068 > 40464 file_move 180.6429 > 32374 file_kill 144.5268 > 25316 atomic_dec_and_lock 98.8906 > 24814 clear_page 155.0875 > 17709 file_ra_state_init 110.6813 > 17603 clear_page_tables 13.4169 file_move()? file_kill()? I smell files_lock. -- wli ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 16:16 kernbench on 512p Jesse Barnes 2004-08-19 16:22 ` William Lee Irwin III @ 2004-08-19 16:29 ` David Mosberger 2004-08-19 16:37 ` Jesse Barnes 2004-08-19 23:03 ` William Lee Irwin III 2004-08-20 0:56 ` remove dentry_open::file_ra_init_state() duplicated memset was " Marcelo Tosatti 3 siblings, 1 reply; 35+ messages in thread From: David Mosberger @ 2004-08-19 16:29 UTC (permalink / raw) To: Jesse Barnes; +Cc: linux-kernel >>>>> On Thu, 19 Aug 2004 12:16:33 -0400, Jesse Barnes <jbarnes@engr.sgi.com> said: Jesse> It would be nice if the patch to show which lock is contended Jesse> got included. Why not use q-syscollect? It will show you the caller of ia64_spinlock_contention, which is often just as good (or better ;-). --david ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 16:29 ` David Mosberger @ 2004-08-19 16:37 ` Jesse Barnes 2004-08-19 16:40 ` David Mosberger 2004-08-19 18:25 ` Martin J. Bligh 0 siblings, 2 replies; 35+ messages in thread From: Jesse Barnes @ 2004-08-19 16:37 UTC (permalink / raw) To: davidm; +Cc: linux-kernel On Thursday, August 19, 2004 12:29 pm, David Mosberger wrote: > >>>>> On Thu, 19 Aug 2004 12:16:33 -0400, Jesse Barnes > >>>>> <jbarnes@engr.sgi.com> said: > > Jesse> It would be nice if the patch to show which lock is contended > Jesse> got included. > > Why not use q-syscollect? It will show you the caller of > ia64_spinlock_contention, which is often just as good (or better ;-). Because it requires guile and guile SLIB, which I've never been able to setup properly on a RHEL3 based distro. Care to rewrite the tools in C or something? ;) Jesse ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 16:37 ` Jesse Barnes @ 2004-08-19 16:40 ` David Mosberger 2004-08-19 17:55 ` Alan Cox 2004-08-19 18:25 ` Martin J. Bligh 1 sibling, 1 reply; 35+ messages in thread From: David Mosberger @ 2004-08-19 16:40 UTC (permalink / raw) To: Jesse Barnes; +Cc: davidm, linux-kernel >>>>> On Thu, 19 Aug 2004 12:37:16 -0400, Jesse Barnes <jbarnes@engr.sgi.com> said: Jesse> On Thursday, August 19, 2004 12:29 pm, David Mosberger wrote: >> >>>>> On Thu, 19 Aug 2004 12:16:33 -0400, Jesse Barnes >>>>> >> <jbarnes@engr.sgi.com> said: >> Jesse> It would be nice if the patch to show which lock is contended Jesse> got included. >> Why not use q-syscollect? It will show you the caller of >> ia64_spinlock_contention, which is often just as good (or better >> ;-). Jesse> Because it requires guile and guile SLIB, which I've never Jesse> been able to setup properly on a RHEL3 based distro. Care to Jesse> rewrite the tools in C or something? ;) Why not file a bug-report to Red Hat instead? guile v1.6 and the guile-SLIB are quite old and rather standard. Of course, you could also run the analysis on a Debian system, which comes standard with those packages. --david ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 16:40 ` David Mosberger @ 2004-08-19 17:55 ` Alan Cox 2004-08-20 7:53 ` David Mosberger 0 siblings, 1 reply; 35+ messages in thread From: Alan Cox @ 2004-08-19 17:55 UTC (permalink / raw) To: davidm; +Cc: Jesse Barnes, Linux Kernel Mailing List On Iau, 2004-08-19 at 17:40, David Mosberger wrote: > Why not file a bug-report to Red Hat instead? guile v1.6 and the > guile-SLIB are quite old and rather standard. On debian maybe. The enterprise demand for guile-slib is suprisingly low ;) ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 17:55 ` Alan Cox @ 2004-08-20 7:53 ` David Mosberger 0 siblings, 0 replies; 35+ messages in thread From: David Mosberger @ 2004-08-20 7:53 UTC (permalink / raw) To: Alan Cox; +Cc: davidm, Jesse Barnes, Linux Kernel Mailing List >>>>> On Thu, 19 Aug 2004 18:55:22 +0100, Alan Cox <alan@lxorguk.ukuu.org.uk> said: Alan> On Iau, 2004-08-19 at 17:40, David Mosberger wrote: >> Why not file a bug-report to Red Hat instead? guile v1.6 and the >> guile-SLIB are quite old and rather standard. Alan> On debian maybe. Alan> The enterprise demand for guile-slib is suprisingly low ;) Ever heard of the chicken-and-egg problem? Is there any good reason _not_ to provide guile-slib? I'm not aware of any. --david ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 16:37 ` Jesse Barnes 2004-08-19 16:40 ` David Mosberger @ 2004-08-19 18:25 ` Martin J. Bligh 2004-08-19 18:42 ` Jesse Barnes 2004-08-19 21:11 ` Jesse Barnes 1 sibling, 2 replies; 35+ messages in thread From: Martin J. Bligh @ 2004-08-19 18:25 UTC (permalink / raw) To: Jesse Barnes, davidm; +Cc: linux-kernel > On Thursday, August 19, 2004 12:29 pm, David Mosberger wrote: >> >>>>> On Thu, 19 Aug 2004 12:16:33 -0400, Jesse Barnes >> >>>>> <jbarnes@engr.sgi.com> said: >> >> Jesse> It would be nice if the patch to show which lock is contended >> Jesse> got included. >> >> Why not use q-syscollect? It will show you the caller of >> ia64_spinlock_contention, which is often just as good (or better ;-). > > Because it requires guile and guile SLIB, which I've never been able to setup > properly on a RHEL3 based distro. Care to rewrite the tools in C or > something? ;) Does lockmeter not work for you? It's sitting in my tree still, and Andrew's last time I looked. M. ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 18:25 ` Martin J. Bligh @ 2004-08-19 18:42 ` Jesse Barnes 2004-08-19 21:11 ` Jesse Barnes 1 sibling, 0 replies; 35+ messages in thread From: Jesse Barnes @ 2004-08-19 18:42 UTC (permalink / raw) To: Martin J. Bligh; +Cc: davidm, linux-kernel On Thursday, August 19, 2004 2:25 pm, Martin J. Bligh wrote: > Does lockmeter not work for you? It's sitting in my tree still, and > Andrew's last time I looked. I haven't tried it recently. I'm building a kernel with lockmetering enabled now. Jesse ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 18:25 ` Martin J. Bligh 2004-08-19 18:42 ` Jesse Barnes @ 2004-08-19 21:11 ` Jesse Barnes 2004-08-19 21:24 ` Jesse Barnes 2004-08-19 21:50 ` Ray Bryant 1 sibling, 2 replies; 35+ messages in thread From: Jesse Barnes @ 2004-08-19 21:11 UTC (permalink / raw) To: Martin J. Bligh; +Cc: hawkes, linux-kernel, wli [-- Attachment #1: Type: text/plain, Size: 760 bytes --] On Thursday, August 19, 2004 2:25 pm, Martin J. Bligh wrote: > Does lockmeter not work for you? It's sitting in my tree still, and > Andrew's last time I looked. Ok, it seems to work at least a little (btw, oprofile cause the machine to be unusable whenever a bunch of processes started up). I got a bunch of scary messages like these though: For cpu 140 entry 998 incremented kernel count=3 Bad kernel cum_hold_ticks=-8658575876528 (FFFFF82004A91E50) for cpu=140 index=999 For cpu 140 entry 999 incremented kernel count=3 John, what does that mean? The lock contention was heavy, but I wouldn't think that we'd overflow a 64 bit tick counter... The output is attached (my mailer insists on wrapping it if I inline it). I used 'lockstat -w'. Jesse [-- Attachment #2: lockstat-3.txt --] [-- Type: text/plain, Size: 15239 bytes --] ___________________________________________________________________________________________ System: Linux ascender.americas.sgi.com 2.6.8.1-mm1 #4 SMP Thu Aug 19 13:05:16 PDT 2004 ia64 Total counts All (512) CPUs Selecting locks that meet ALL of the following: requests/sec: > 0.00/sec contention : > 0.00% utilization : > 0.00% Start time: Thu Aug 19 15:52:55 2004 End time: Thu Aug 19 15:53:57 2004 Delta Time: 62.51 sec. Hash table slots in use: 343. Global read lock slots in use: 999. ./lockstat: One or more warnings were printed with the report. *************************** Warnings! ****************************** Read Lock table overflowed. The data in this report may be in error due to this. ************************ End of Warnings! ************************** - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - SPINLOCKS HOLD WAIT UTIL CON MEAN( MAX ) MEAN( MAX )(% CPU) TOTAL NOWAIT SPIN RJECT NAME 1.1% 6.9us( 158ms) 33ms(1015ms)(51.4%) 47254182 98.9% 1.1% 0.03% *TOTAL* 0.08% 0.11% 1.4us( 253us) 1448us( 17ms)(0.00%) 35255 99.9% 0.11% 0% [0xe00000b0037fe5d0] 0.00% 0% 8.7us( 19us) 0us 14 100% 0% 0% xfs_log_need_covered+0x100 0.01% 0.10% 1.1us( 34us) 775us(2977us)(0.00%) 3848 99.9% 0.10% 0% xfs_log_notify+0x40 0.00% 0% 3.4us( 44us) 0us 181 100% 0% 0% xlog_state_do_callback+0x50 0.00% 0% 0.1us( 1.2us) 0us 181 100% 0% 0% xlog_state_do_callback+0x410 0.00% 0% 2.0us( 17us) 0us 181 100% 0% 0% xlog_state_do_callback+0x480 0.00% 0% 0.2us( 0.6us) 0us 182 100% 0% 0% xlog_state_done_syncing+0x40 0.03% 0.17% 2.8us( 80us) 935us( 12ms)(0.00%) 7853 99.8% 0.17% 0% xlog_state_get_iclog_space+0x30 0.01% 0.11% 2.4us( 41us) 15us( 40us)(0.00%) 3506 99.9% 0.11% 0% xlog_state_put_ticket+0x20 0.00% 0.06% 0.1us( 48us) 458us(2212us)(0.00%) 7875 100% 0.06% 0% xlog_state_release_iclog+0x50 0.00% 0% 10us( 29us) 0us 32 100% 0% 0% xlog_state_sync_all+0x30 0.00% 0% 0.8us( 15us) 0us 21 100% 0% 0% xlog_state_sync_all+0x420 0.00% 0% 10.0us(10.0us) 0us 1 100% 0% 0% xlog_state_sync+0x40 0.00% 0% 20us( 20us) 0us 1 100% 0% 0% xlog_state_sync+0x3d0 0.00% 0% 3.1us( 20us) 0us 25 100% 0% 0% xlog_state_want_sync+0x20 0.01% 0.29% 1.2us( 63us) 3883us( 17ms)(0.00%) 3506 99.7% 0.29% 0% xlog_ticket_get+0x50 0.01% 0.04% 1.1us( 253us) 9.0us( 17us)(0.00%) 7694 100% 0.04% 0% xlog_write+0x590 0.00% 0% 6.3us( 41us) 0us 25 100% 0% 0% xlog_write+0x660 0.00% 0% 0.5us( 19us) 0us 129 100% 0% 0% xlog_write+0x7a0 0.12% 0.22% 3.1us( 101us) 2272us( 31ms)(0.00%) 25111 99.8% 0.22% 0% [0xe00000b0037fe670] 0.02% 0.13% 3.5us( 55us) 10ms( 27ms)(0.00%) 3888 99.9% 0.13% 0% xfs_log_move_tail+0x70 0.00% 0.27% 0.1us( 22us) 1373us( 28ms)(0.00%) 7875 99.7% 0.27% 0% xlog_assign_tail_lsn+0x50 0.06% 0.29% 10us( 101us) 3117us( 31ms)(0.00%) 3506 99.7% 0.29% 0% xlog_grant_log_space+0x30 0.02% 0.23% 3.2us( 88us) 1293us( 11ms)(0.00%) 4745 99.8% 0.23% 0% xlog_grant_push_ail+0x50 0.00% 0.08% 2.2us( 29us) 22us( 22us)(0.00%) 1239 100% 0.08% 0% xlog_regrant_reserve_log_space+0x60 0.01% 0% 26us( 63us) 0us 171 100% 0% 0% xlog_regrant_write_log_space+0x90 0.00% 0% 0.0us( 0.1us) 0us 181 100% 0% 0% xlog_state_do_callback+0x3c0 0.01% 0.23% 1.0us( 40us) 185us(1307us)(0.00%) 3506 99.8% 0.23% 0% xlog_ungrant_log_space+0x50 0.02% 0.14% 0.5us( 203us) 1261us( 15ms)(0.00%) 29681 99.9% 0.14% 0% [0xe000193003e3e024] 0.00% 0% 0.2us( 12us) 0us 364 100% 0% 0% xfs_buf_iodone+0x30 0.00% 0% 0.1us( 4.9us) 0us 170 100% 0% 0% xfs_efi_item_unpin+0x30 0.00% 0% 0.1us( 3.4us) 0us 170 100% 0% 0% xfs_efi_release+0x40 0.00% 0.50% 0.1us( 6.6us) 6.1us( 12us)(0.00%) 2004 99.5% 0.50% 0% xfs_iflush_done+0xc0 0.00% 0.50% 0.8us( 29us) 18us( 89us)(0.00%) 2004 99.5% 0.50% 0% xfs_iflush_int+0x3f0 0.00% 0.01% 0.2us( 17us) 35us( 36us)(0.00%) 15515 100% 0.01% 0% xfs_trans_chunk_committed+0x220 0.00% 50.0% 124us( 203us) 14ms( 15ms)(0.00%) 6 50.0% 50.0% 0% xfs_trans_push_ail+0x40 0.01% 0.57% 2.1us( 56us) 19us( 94us)(0.00%) 1567 99.4% 0.57% 0% xfs_trans_push_ail+0x2b0 0.00% 0% 1.7us( 10us) 0us 6 100% 0% 0% xfs_trans_push_ail+0x420 0.01% 0.11% 0.7us( 35us) 1319us( 12ms)(0.00%) 7875 99.9% 0.11% 0% xfs_trans_tail_ail+0x30 0.04% 0.08% 1.4us( 65us) 77us( 871us)(0.00%) 19294 100% 0.08% 0% [0xe000193003e3e110] 0.04% 0.07% 1.6us( 65us) 23us( 51us)(0.00%) 16434 100% 0.07% 0% xfs_mod_incore_sb+0x20 0.00% 0.17% 0.6us( 65us) 196us( 871us)(0.00%) 2859 99.8% 0.17% 0% xfs_mod_incore_sb_batch+0x30 0.00% 0% 22us( 22us) 0us 1 100% 0% 0% xfs_statvfs+0x40 0.09% 0.36% 4.5us( 824us) 27us( 342us)(0.00%) 12079 99.6% 0.36% 0% [0xe000353003c8e040] 0.08% 0.62% 22us( 824us) 22us( 201us)(0.00%) 2419 99.4% 0.62% 0% qla1280_intr_handler+0x30 0.00% 0.17% 0.8us( 25us) 15us( 40us)(0.00%) 2415 99.8% 0.17% 0% scsi_device_unbusy+0x40 0% 0.04% 3.9us( 3.9us)(0.00%) 2415 100% 0.04% 0% scsi_dispatch_cmd+0x330 0% 0.50% 55us( 342us)(0.00%) 2415 99.5% 0.50% 0% scsi_request_fn+0x260 0% 0.50% 13us( 29us)(0.00%) 2415 99.5% 0.50% 0% scsi_run_queue+0xa0 0.14% 1.2% 3.1us(2630us) 81us(5265us)(0.00%) 28773 98.8% 1.2% 0% [0xe00039b003b6b834] 0.00% 1.1% 0.2us( 204us) 76us(1582us)(0.00%) 11558 98.9% 1.1% 0% __make_request+0x150 0.02% 1.3% 4.0us( 182us) 19us( 59us)(0.00%) 2415 98.7% 1.3% 0% blk_run_queue+0x40 0.11% 1.0% 52us(2630us) 747us(5265us)(0.00%) 1342 99.0% 1.0% 0% generic_unplug_device+0x40 0% 0.50% 172us(1021us)(0.00%) 2415 99.5% 0.50% 0% get_request+0x80 0% 0.91% 25us( 124us)(0.00%) 2415 99.1% 0.91% 0% scsi_device_unbusy+0xd0 0% 1.6% 22us( 113us)(0.00%) 2415 98.4% 1.6% 0% scsi_end_request+0x160 0.01% 4.2% 3.5us( 132us) 40us( 310us)(0.00%) 2415 95.8% 4.2% 0% scsi_request_fn+0x4a0 0% 0.08% 57us( 97us)(0.00%) 3798 100% 0.08% 0% scsi_request_fn+0x540 71.7% 81.0% 82us( 16ms) 36ms(1015ms)(49.3%) 545870 19.0% 81.0% 0% dcache_lock 0.10% 96.7% 74us(1190us) 39ms( 403ms)(0.10%) 869 3.3% 96.7% 0% d_alloc+0x270 0.05% 97.3% 132us(1058us) 39ms( 325ms)(0.03%) 259 2.7% 97.3% 0% d_delete+0x40 0.15% 81.7% 60us(1273us) 36ms( 446ms)(0.14%) 1533 18.3% 81.7% 0% d_instantiate+0x90 0.06% 95.3% 184us(1082us) 33ms( 217ms)(0.02%) 212 4.7% 95.3% 0% d_move+0x60 0.13% 65.4% 95us(1045us) 35ms( 356ms)(0.06%) 869 34.6% 65.4% 0% d_rehash+0xe0 71.1% 80.9% 82us( 16ms) 36ms(1015ms)(48.8%) 540564 19.1% 80.9% 0% dput+0x40 0.16% 89.5% 66us( 902us) 40ms( 336ms)(0.17%) 1536 10.5% 89.5% 0% link_path_walk+0xef0 0.00% 100% 91us( 326us) 43ms( 134ms)(0.00%) 28 0% 100% 0% sys_getcwd+0x210 0.94% 3.0% 3.7us(4918us) 1113us( 43ms)(0.02%) 157922 97.0% 3.0% 0% files_lock 0.00% 0.83% 0.6us( 21us) 71us( 148us)(0.00%) 360 99.2% 0.83% 0% check_tty_count+0x40 0.06% 1.7% 0.5us(4918us) 1127us( 43ms)(0.00%) 78366 98.3% 1.7% 0% file_kill+0x60 0.87% 4.4% 6.9us( 289us) 1109us( 43ms)(0.01%) 79196 95.6% 4.4% 0% file_move+0x40 0.78% 0.33% 11us(6090us) 584us( 20ms)(0.00%) 43999 99.7% 0.33% 0% inode_lock 0.02% 1.3% 2.5us(1019us) 638us( 16ms)(0.00%) 4654 98.7% 1.3% 0% __mark_inode_dirty+0xf0 0.55% 0.20% 34us(6090us) 35us( 82us)(0.00%) 10047 99.8% 0.20% 0% __sync_single_inode+0xf0 0.00% 0.77% 1.1us( 24us) 42us( 60us)(0.00%) 390 99.2% 0.77% 0% generic_delete_inode+0x260 0.03% 1.3% 20us( 83us) 57us( 143us)(0.00%) 796 98.7% 1.3% 0% get_new_inode_fast+0x50 0.02% 1.0% 15us( 87us) 3385us( 20ms)(0.00%) 796 99.0% 1.0% 0% iget_locked+0xd0 0.01% 0.51% 2.5us( 51us) 44us( 132us)(0.00%) 2743 99.5% 0.51% 0% igrab+0x20 0.06% 0.19% 2.8us( 162us) 561us(8501us)(0.00%) 13905 99.8% 0.19% 0% iput+0xb0 0.02% 0.45% 28us( 116us) 1018us(2019us)(0.00%) 449 99.6% 0.45% 0% new_inode+0x60 0.06% 0% 3.6us( 200us) 0us 10047 100% 0% 0% sync_sb_inodes+0x570 0.01% 0.58% 37us( 166us) 27us( 27us)(0.00%) 172 99.4% 0.58% 0% writeback_inodes+0x30 0.25% 0.06% 89us(1143us) 300us( 300us)(0.00%) 1771 100% 0.06% 0% kernel_flag 0.10% 0% 340us(1143us) 0us 192 100% 0% 0% chrdev_open+0x1c0 0.00% 0% 2.2us( 21us) 0us 131 100% 0% 0% de_put+0x50 0.00% 0% 0.1us( 7.5us) 0us 176 100% 0% 0% linvfs_ioctl+0x150 0.09% 0% 416us( 854us) 0us 131 100% 0% 0% proc_lookup+0x60 0.00% 0% 6.8us( 21us) 0us 7 100% 0% 0% schedule+0xc20 0.02% 0.11% 15us( 871us) 300us( 300us)(0.00%) 920 99.9% 0.11% 0% sys_ioctl+0xa0 0.00% 0% 24us( 462us) 0us 21 100% 0% 0% tty_read+0x160 0.04% 0% 127us( 385us) 0us 180 100% 0% 0% tty_release+0x50 0.00% 0% 39us( 428us) 0us 13 100% 0% 0% tty_write+0x3d0 0.10% 1.1% 8.4us( 558us) 51ms( 239ms)(0.01%) 7632 98.9% 1.1% 0% mmlist_lock 0.01% 1.6% 2.4us( 146us) 80ms( 215ms)(0.01%) 1771 98.4% 1.6% 0% copy_mm+0x2c0 0.05% 1.4% 17us( 558us) 55ms( 239ms)(0.00%) 1989 98.6% 1.4% 0% exec_mmap+0x40 0.04% 0.75% 6.8us( 121us) 20ms( 156ms)(0.00%) 3872 99.3% 0.75% 0% mmput+0x40 4.4% 58.6% 48us(7191us) 19ms( 84ms)( 1.9%) 57005 41.4% 58.6% 0% rcu_state 0.01% 38.7% 58us( 679us) 10ms( 41ms)(0.00%) 119 61.3% 38.7% 0% __rcu_process_callbacks+0x260 4.4% 58.6% 48us(7191us) 19ms( 84ms)( 1.9%) 56886 41.4% 58.6% 0% rcu_check_quiescent_state+0xf0 0.00% 0.45% 2.1us( 39us) 3128us(9317us)(0.00%) 665 99.5% 0.45% 0% vnumber_lock 0.00% 0.45% 2.1us( 39us) 3128us(9317us)(0.00%) 665 99.5% 0.45% 0% vn_initialize+0xb0 1.0% 0.00% 9.9us(1399us) 3843us(3843us)(0.00%) 64014 100% 0.00% 0% xtime_lock+0x4 0.00% 0% 20us( 28us) 0us 2 100% 0% 0% do_adjtimex+0x1a0 1.0% 0.00% 9.9us(1399us) 3843us(3843us)(0.00%) 64012 100% 0.00% 0% timer_interrupt+0x2a0 0.24% 0.17% 0.4us( 32ms) 686us( 32ms)(0.00%) 414014 99.8% 0.17% 0% __d_lookup+0x1b0 0.07% 0.01% 3.1us( 124us) 15us( 15us)(0.00%) 13477 100% 0.01% 0% _pagebuf_find+0xf0 0.03% 0.00% 0.5us( 60us) 9.9us( 17us)(0.00%) 45039 100% 0.00% 0% anon_vma_unlink+0x40 0.31% 0.14% 9.6us( 243us) 26us( 114us)(0.00%) 20408 99.9% 0.14% 0% cache_alloc_refill+0xd0 0.01% 0.18% 0.4us( 42us) 16ms( 55ms)(0.00%) 21913 99.8% 0.18% 0% copy_mm+0x6f0 0.02% 0.09% 1.2us( 340us) 6.6us( 30us)(0.00%) 11937 100% 0.09% 0% deny_write_access+0x40 0.11% 0.06% 0.9us( 14ms) 8.4us( 42us)(0.00%) 80024 100% 0.06% 0% dnotify_parent+0x70 2.5% 2.4% 2.5us( 789us) 0us 608901 97.6% 0% 2.4% double_lock_balance+0x20 0.07% 66.0% 6.7us( 338us) 939us( 149ms)(0.01%) 6226 34.0% 66.0% 0% double_lock_balance+0x90 0.14% 52.9% 6.3us( 412us) 3804us( 158ms)(0.09%) 14339 47.1% 52.9% 0% double_lock_balance+0xb0 0.00% 0.41% 2.3us( 31us) 2.8us( 3.9us)(0.00%) 482 99.6% 0.41% 0% double_rq_lock+0x60 0.00% 0.73% 2.9us( 179us) 376us( 750us)(0.00%) 274 99.3% 0.73% 0% double_rq_lock+0x90 0.10% 0.00% 0.8us( 297us) 4.9us( 5.8us)(0.00%) 75211 100% 0.00% 0% dput+0x80 0.13% 1.4% 0.4us( 307us) 138us( 30ms)(0.00%) 194583 98.6% 1.4% 0% load_balance+0x170 422% 0.01% 66us( 158ms) 31us(5303us)(0.00%) 3989432 100% 0.01% 0% load_balance+0x30 0.05% 0.81% 4.7us( 22ms) 15us( 58us)(0.00%) 6686 99.2% 0.81% 0% migration_thread+0x110 0.11% 0.16% 1.0us( 557us) 6661us( 58ms)(0.00%) 72120 99.8% 0.16% 0% remove_vm_struct+0x60 0.56% 1.8% 2.3us(1112us) 12us( 67us)(0.00%) 151051 98.2% 1.8% 0% schedule+0x290 2.3% 0.01% 0.2us(7619us) 92us(9305us)(0.00%) 9418925 100% 0.01% 0% scheduler_tick+0x370 0.07% 0.21% 5.3us(4483us) 15us( 158us)(0.00%) 8470 99.8% 0.21% 0% vma_adjust+0x140 0.40% 0.11% 5.9us( 43ms) 1567us( 39ms)(0.00%) 42753 99.9% 0.11% 0% vma_link+0x70 - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - RWLOCK READS HOLD MAX RDR BUSY PERIOD WAIT UTIL CON MEAN RDRS MEAN( MAX ) MEAN( MAX )( %CPU) TOTAL NOWAIT SPIN NAME 0.07% 49us( 558us)(0.00%) 457364 100% 0.07% *TOTAL* 131% 3.6% 9.8us 2 9874us(45704ms) 49us( 558us)(0.00%) 8357 96.4% 3.6% tasklist_lock 0.94% 113us( 282us)(0.00%) 3180 99.1% 0.94% do_sigaction+0x270 5.4% 42us( 558us)(0.00%) 5107 94.6% 5.4% do_wait+0x120 0% 0us 66 100% 0% send_group_sig_info+0x30 0% 0us 4 100% 0% session_of_pgrp+0x40 - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - RWLOCK WRITES HOLD WAIT (ALL) WAIT (WW) UTIL CON MEAN( MAX ) MEAN( MAX )( %CPU) MEAN( MAX ) TOTAL NOWAIT SPIN( WW ) NAME 0.41% 0.1us( 178us) 2097us( 47ms)(0.00%) 1313us( 47ms) 23738 99.6% 0.08%(0.33%) *TOTAL* _________________________________________________________________________________________________________________________ Number of read locks found=1 ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 21:11 ` Jesse Barnes @ 2004-08-19 21:24 ` Jesse Barnes 2004-08-19 21:56 ` Martin J. Bligh 2004-08-19 23:38 ` Paul E. McKenney 2004-08-19 21:50 ` Ray Bryant 1 sibling, 2 replies; 35+ messages in thread From: Jesse Barnes @ 2004-08-19 21:24 UTC (permalink / raw) To: Martin J. Bligh; +Cc: hawkes, linux-kernel, wli On Thursday, August 19, 2004 5:11 pm, Jesse Barnes wrote: > The output is attached (my mailer insists on wrapping it if I inline it). > I used 'lockstat -w'. The highlights: nw spin rjct lock & function 19.0% 81.0% 0% dcache_lock 3.3% 96.7% 0% d_alloc+0x270 2.7% 97.3% 0% d_delete+0x40 18.3% 81.7% 0% d_instantiate+0x90 4.7% 95.3% 0% d_move+0x60 34.6% 65.4% 0% d_rehash+0xe0 19.1% 80.9% 0% dput+0x40 10.5% 89.5% 0% link_path_walk+0xef0 0% 100% 0% sys_getcwd+0x210 41.4% 58.6% 0% rcu_state 61.3% 38.7% 0% __rcu_process_callbacks+0x260 41.4% 58.6% 0% rcu_check_quiescent_state+0xf0 So it looks like the dcache lock is the biggest problem on this system with this load. And although the rcu stuff has improved tremendously for this system, it's still highly contended. Jesse ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 21:24 ` Jesse Barnes @ 2004-08-19 21:56 ` Martin J. Bligh 2004-08-20 19:36 ` Maneesh Soni 2004-08-19 23:38 ` Paul E. McKenney 1 sibling, 1 reply; 35+ messages in thread From: Martin J. Bligh @ 2004-08-19 21:56 UTC (permalink / raw) To: Jesse Barnes; +Cc: hawkes, linux-kernel, wli --On Thursday, August 19, 2004 17:24:04 -0400 Jesse Barnes <jbarnes@engr.sgi.com> wrote: > On Thursday, August 19, 2004 5:11 pm, Jesse Barnes wrote: >> The output is attached (my mailer insists on wrapping it if I inline it). >> I used 'lockstat -w'. > > The highlights: > > nw spin rjct lock & function > 19.0% 81.0% 0% dcache_lock > 3.3% 96.7% 0% d_alloc+0x270 > 2.7% 97.3% 0% d_delete+0x40 > 18.3% 81.7% 0% d_instantiate+0x90 > 4.7% 95.3% 0% d_move+0x60 > 34.6% 65.4% 0% d_rehash+0xe0 > 19.1% 80.9% 0% dput+0x40 > 10.5% 89.5% 0% link_path_walk+0xef0 > 0% 100% 0% sys_getcwd+0x210 > > 41.4% 58.6% 0% rcu_state > 61.3% 38.7% 0% __rcu_process_callbacks+0x260 > 41.4% 58.6% 0% rcu_check_quiescent_state+0xf0 > > So it looks like the dcache lock is the biggest problem on this system with > this load. And although the rcu stuff has improved tremendously for this > system, it's still highly contended. Hmmm. dcache_lock is known-fucked, though I'm suprised at d_rehash (file deletion)? RCU stuff is a bit sad. M. ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 21:56 ` Martin J. Bligh @ 2004-08-20 19:36 ` Maneesh Soni 0 siblings, 0 replies; 35+ messages in thread From: Maneesh Soni @ 2004-08-20 19:36 UTC (permalink / raw) To: Martin J. Bligh; +Cc: Jesse Barnes, hawkes, linux-kernel, wli On Thu, Aug 19, 2004 at 02:56:39PM -0700, Martin J. Bligh wrote: > --On Thursday, August 19, 2004 17:24:04 -0400 Jesse Barnes <jbarnes@engr.sgi.com> wrote: > > > On Thursday, August 19, 2004 5:11 pm, Jesse Barnes wrote: > >> The output is attached (my mailer insists on wrapping it if I inline it). > >> I used 'lockstat -w'. > > > > The highlights: > > > > nw spin rjct lock & function > > 19.0% 81.0% 0% dcache_lock > > 3.3% 96.7% 0% d_alloc+0x270 > > 2.7% 97.3% 0% d_delete+0x40 > > 18.3% 81.7% 0% d_instantiate+0x90 > > 4.7% 95.3% 0% d_move+0x60 > > 34.6% 65.4% 0% d_rehash+0xe0 > > 19.1% 80.9% 0% dput+0x40 > > 10.5% 89.5% 0% link_path_walk+0xef0 > > 0% 100% 0% sys_getcwd+0x210 > > > > 41.4% 58.6% 0% rcu_state > > 61.3% 38.7% 0% __rcu_process_callbacks+0x260 > > 41.4% 58.6% 0% rcu_check_quiescent_state+0xf0 > > > > So it looks like the dcache lock is the biggest problem on this system with > > this load. And although the rcu stuff has improved tremendously for this > > system, it's still highly contended. > > Hmmm. dcache_lock is known-fucked, though I'm suprised at d_rehash > (file deletion)? > The thing which is hurting most is dput(), almost 90% of the dcache_lock aquistion is there. (deleted few columns) 23.8% 67.3% 9955785 32.7% 67.3% 0% dcache_lock 0.06% 70.5% 17068 29.5% 70.5% 0% d_alloc+0x270 0.02% 25.4% 15340 74.6% 25.4% 0% d_delete+0x40 0.06% 65.9% 30485 34.1% 65.9% 0% d_instantiate+0x90 0.06% 78.0% 4461 22.0% 78.0% 0% d_move+0x60 0.00% 0% 2 100% 0% 0% d_path+0x120 0.04% 52.5% 17068 47.5% 52.5% 0% d_rehash+0xe0 0.00% 26.7% 15 73.3% 26.7% 0% d_splice_alias+0xc0 0.00% 20.0% 5 80.0% 20.0% 0% dentry_unhash+0x70 0.00% 0% 4 100% 0% 0% dentry_unhash+0xc0 23.5% 67.5% 9827270 32.5% 67.5% 0% dput+0x40 0.09% 62.3% 36875 37.7% 62.3% 0% link_path_walk+0xef0 0.00% 0.24% 5068 99.8% 0.24% 0% link_path_walk+0x1cc0 0.00% 33.3% 3 66.7% 33.3% 0% proc_pid_unhash+0x50 0.00% 7.1% 14 92.9% 7.1% 0% prune_dcache+0x50 0.00% 0% 167 100% 0% 0% prune_dcache+0x3d0 0.00% 0% 21 100% 0% 0% select_parent+0x40 0.00% 24.2% 1919 75.8% 24.2% 0% sys_getcwd+0x210 -- Maneesh Soni Linux Technology Center, IBM Austin email: maneesh@in.ibm.com Phone: 1-512-838-1896 Fax: T/L : 6781896 ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 21:24 ` Jesse Barnes 2004-08-19 21:56 ` Martin J. Bligh @ 2004-08-19 23:38 ` Paul E. McKenney 2004-08-20 0:16 ` Jesse Barnes 1 sibling, 1 reply; 35+ messages in thread From: Paul E. McKenney @ 2004-08-19 23:38 UTC (permalink / raw) To: Jesse Barnes; +Cc: Martin J. Bligh, hawkes, linux-kernel, wli On Thu, Aug 19, 2004 at 05:24:04PM -0400, Jesse Barnes wrote: > On Thursday, August 19, 2004 5:11 pm, Jesse Barnes wrote: > > The output is attached (my mailer insists on wrapping it if I inline it). > > I used 'lockstat -w'. > > The highlights: > > nw spin rjct lock & function > 19.0% 81.0% 0% dcache_lock > 3.3% 96.7% 0% d_alloc+0x270 > 2.7% 97.3% 0% d_delete+0x40 > 18.3% 81.7% 0% d_instantiate+0x90 > 4.7% 95.3% 0% d_move+0x60 > 34.6% 65.4% 0% d_rehash+0xe0 > 19.1% 80.9% 0% dput+0x40 > 10.5% 89.5% 0% link_path_walk+0xef0 > 0% 100% 0% sys_getcwd+0x210 > > 41.4% 58.6% 0% rcu_state > 61.3% 38.7% 0% __rcu_process_callbacks+0x260 > 41.4% 58.6% 0% rcu_check_quiescent_state+0xf0 > > So it looks like the dcache lock is the biggest problem on this system with > this load. And although the rcu stuff has improved tremendously for this > system, it's still highly contended. Was this run using all of Manfred's RCU patches? If not, it would be interesting to see what you get with full RCU_HUGE patchset. Thanx, Paul ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 23:38 ` Paul E. McKenney @ 2004-08-20 0:16 ` Jesse Barnes 2004-08-20 15:57 ` Paul E. McKenney 0 siblings, 1 reply; 35+ messages in thread From: Jesse Barnes @ 2004-08-20 0:16 UTC (permalink / raw) To: paulmck; +Cc: Martin J. Bligh, hawkes, linux-kernel, wli On Thursday, August 19, 2004 7:38 pm, Paul E. McKenney wrote: > > 41.4% 58.6% 0% rcu_state > > 61.3% 38.7% 0% __rcu_process_callbacks+0x260 > > 41.4% 58.6% 0% rcu_check_quiescent_state+0xf0 > > > > So it looks like the dcache lock is the biggest problem on this system > > with this load. And although the rcu stuff has improved tremendously for > > this system, it's still highly contended. > > Was this run using all of Manfred's RCU patches? If not, it would be > interesting to see what you get with full RCU_HUGE patchset. So that stuff isn't in 2.6.8.1-mm1? What I tested was pretty close to a stock version of that tree. Where can I grab a version of that patchset that applies to a recent kernel? Thanks, Jesse ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-20 0:16 ` Jesse Barnes @ 2004-08-20 15:57 ` Paul E. McKenney 2004-08-20 17:24 ` Jesse Barnes 0 siblings, 1 reply; 35+ messages in thread From: Paul E. McKenney @ 2004-08-20 15:57 UTC (permalink / raw) To: Jesse Barnes; +Cc: Martin J. Bligh, hawkes, linux-kernel, wli On Thu, Aug 19, 2004 at 08:16:10PM -0400, Jesse Barnes wrote: > On Thursday, August 19, 2004 7:38 pm, Paul E. McKenney wrote: > > > 41.4% 58.6% 0% rcu_state > > > 61.3% 38.7% 0% __rcu_process_callbacks+0x260 > > > 41.4% 58.6% 0% rcu_check_quiescent_state+0xf0 > > > > > > So it looks like the dcache lock is the biggest problem on this system > > > with this load. And although the rcu stuff has improved tremendously for > > > this system, it's still highly contended. > > > > Was this run using all of Manfred's RCU patches? If not, it would be > > interesting to see what you get with full RCU_HUGE patchset. > > So that stuff isn't in 2.6.8.1-mm1? What I tested was pretty close to a stock > version of that tree. Where can I grab a version of that patchset that > applies to a recent kernel? If I am not too confused, you need #4 and #5 out of Manfred's set of five RCU_HUGE patchset. They are at: http://marc.theaimsgroup.com/?l=linux-kernel&m=108546358123902&w=2 http://marc.theaimsgroup.com/?l=linux-kernel&m=108546384711797&w=2 A little work will be required to get them to apply. For example, in the first patch, instead of: spin_lock(&rcu_state.mutex); one would say: spin_lock(&rsp->lock); due to the addition of the _bh() primitives. The "rcu_ctrlblk." and "rcu_state." have been replaced by pointers in order to handle multiple different types of grace periods: o Traditional grace periods based on context switch, executing in user mode, or running the idle loop. o New-age low-latency grace periods based on running with interrupts enabled. Thanx, Paul ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-20 15:57 ` Paul E. McKenney @ 2004-08-20 17:24 ` Jesse Barnes 2004-08-20 19:22 ` Manfred Spraul 2004-08-20 20:19 ` Manfred Spraul 0 siblings, 2 replies; 35+ messages in thread From: Jesse Barnes @ 2004-08-20 17:24 UTC (permalink / raw) To: paulmck; +Cc: Martin J. Bligh, hawkes, linux-kernel, wli, manfred On Friday, August 20, 2004 11:57 am, Paul E. McKenney wrote: > If I am not too confused, you need #4 and #5 out of Manfred's set of > five RCU_HUGE patchset. They are at: > > http://marc.theaimsgroup.com/?l=linux-kernel&m=108546358123902&w=2 > http://marc.theaimsgroup.com/?l=linux-kernel&m=108546384711797&w=2 > > A little work will be required to get them to apply. For example, in > the first patch, instead of: > > spin_lock(&rcu_state.mutex); > > one would say: > > spin_lock(&rsp->lock); > > due to the addition of the _bh() primitives. The "rcu_ctrlblk." > and "rcu_state." have been replaced by pointers in order to handle > multiple different types of grace periods: > > o Traditional grace periods based on context switch, executing > in user mode, or running the idle loop. > > o New-age low-latency grace periods based on running with > interrupts enabled. Looks like a bit more context has changed. Manfred, care to respin against -mm3 so I can test? Thanks, Jesse ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-20 17:24 ` Jesse Barnes @ 2004-08-20 19:22 ` Manfred Spraul 2004-08-20 20:19 ` Manfred Spraul 1 sibling, 0 replies; 35+ messages in thread From: Manfred Spraul @ 2004-08-20 19:22 UTC (permalink / raw) To: Jesse Barnes Cc: paulmck, Martin J. Bligh, hawkes, linux-kernel, wli, schwidefsky Jesse Barnes wrote: >Looks like a bit more context has changed. Manfred, care to respin against >-mm3 so I can test? > > > No problem. Btw, who removed rcu_restart_cpu: s390 must call it after changing nohz_cpu_mask. Otherwise a 32-bit wraparound will lead to false quiescent states. -- Manfred ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-20 17:24 ` Jesse Barnes 2004-08-20 19:22 ` Manfred Spraul @ 2004-08-20 20:19 ` Manfred Spraul 2004-08-23 21:23 ` Jesse Barnes 2004-09-10 19:01 ` Greg Edwards 1 sibling, 2 replies; 35+ messages in thread From: Manfred Spraul @ 2004-08-20 20:19 UTC (permalink / raw) To: Jesse Barnes; +Cc: paulmck, Martin J. Bligh, hawkes, linux-kernel, wli [-- Attachment #1: Type: text/plain, Size: 743 bytes --] Jesse Barnes wrote: >Looks like a bit more context has changed. Manfred, care to respin against >-mm3 so I can test? > > > The patches are attached. Just boot-tested on a single-cpu system. Three changes: - I've placed the per-group structure into rcu_state. That's simpler but wrong: the state should be allocated from node-local memory, not a big global array. - I found a bug/race in the cpu_offline path: When the last cpu of a group goes offline then the group must be forced into quiescent state. The "&& (!forced)" was missing. - I've removed the spin_unlock_wait(). It was intended to synchronize cpu_online_mask changes with the calculation of ->outstanding. Paul convinced me that this is not necessary. -- Manfred [-- Attachment #2: patch-rcu268-01-locking --] [-- Type: text/plain, Size: 1847 bytes --] --- 2.6/kernel/rcupdate.c 2004-08-20 19:59:22.000000000 +0200 +++ build-2.6/kernel/rcupdate.c 2004-08-20 20:46:35.952639280 +0200 @@ -237,14 +237,29 @@ * Clear it from the cpu mask and complete the grace period if it was the last * cpu. Start another grace period if someone has further entries pending */ -static void cpu_quiet(int cpu, struct rcu_ctrlblk *rcp, struct rcu_state *rsp) +static void cpu_quiet(int cpu, struct rcu_ctrlblk *rcp, struct rcu_state *rsp, + struct rcu_data *rdp, int force) { + spin_lock(&rsp->lock); + + if (unlikely(rcp->completed == rcp->cur)) + goto out_unlock; + /* + * RCU_quiescbatch/batch.cur and the cpu bitmap can come out of sync + * during cpu startup. Ignore the quiescent state if that happened. + */ + if (unlikely(rdp->quiescbatch != rcp->cur) && likely(!force)) + goto out_unlock; + cpu_clear(cpu, rsp->cpumask); if (cpus_empty(rsp->cpumask)) { /* batch completed ! */ rcp->completed = rcp->cur; rcu_start_batch(rcp, rsp, 0); } +out_unlock: + spin_unlock(&rsp->lock); + } /* @@ -279,15 +294,7 @@ return; rdp->qs_pending = 0; - spin_lock(&rsp->lock); - /* - * rdp->quiescbatch/rcp->cur and the cpu bitmap can come out of sync - * during cpu startup. Ignore the quiescent state. - */ - if (likely(rdp->quiescbatch == rcp->cur)) - cpu_quiet(rdp->cpu, rcp, rsp); - - spin_unlock(&rsp->lock); + cpu_quiet(rdp->cpu, rcp, rsp, rdp, 0); } @@ -314,10 +321,10 @@ * we can block indefinitely waiting for it, so flush * it here */ - spin_lock_bh(&rsp->lock); - if (rcp->cur != rcp->completed) - cpu_quiet(rdp->cpu, rcp, rsp); - spin_unlock_bh(&rsp->lock); + local_bh_disable(); + cpu_quiet(rdp->cpu, rcp, rsp, rdp, 1); + local_bh_enable(); + rcu_move_batch(this_rdp, rdp->curlist, rdp->curtail); rcu_move_batch(this_rdp, rdp->nxtlist, rdp->nxttail); [-- Attachment #3: patch-rcu268-02-groups --] [-- Type: text/plain, Size: 6691 bytes --] --- 2.6/kernel/rcupdate.c 2004-08-20 21:52:45.272210984 +0200 +++ build-2.6/kernel/rcupdate.c 2004-08-20 21:52:24.664343856 +0200 @@ -53,17 +53,59 @@ struct rcu_ctrlblk rcu_bh_ctrlblk = { .cur = -300, .completed = -300 , .lock = SEQCNT_ZERO }; +/* XXX Dummy - should belong into arch XXX */ +#define RCU_HUGE +#define RCU_GROUP_SIZE 2 +/* XXX End of dummy XXX */ + +#ifdef RCU_HUGE + +#define RCU_GROUPCOUNT ((NR_CPUS+RCU_GROUP_SIZE-1)/RCU_GROUP_SIZE) +#define RCU_GROUP_CPUMASKLEN ((RCU_GROUP_SIZE+BITS_PER_LONG-1)/BITS_PER_LONG) +#define RCU_GROUPMASKLEN ((NR_CPUS+RCU_GROUP_SIZE*BITS_PER_LONG-1)/(RCU_GROUP_SIZE*BITS_PER_LONG)) + +struct rcu_group_state { + spinlock_t lock; /* Guard this struct */ + long batchnum; /* batchnum this group is working on. Mitmatch with + * ctrlblk->cur means reinitialize outstanding to + * all active cpus in this group. + */ + unsigned long outstanding[RCU_GROUP_CPUMASKLEN]; +} ____cacheline_maxaligned_in_smp; + +#endif + /* Bookkeeping of the progress of the grace period */ struct rcu_state { spinlock_t lock; /* Guard this struct and writes to rcu_ctrlblk */ +#ifdef RCU_HUGE + long batchnum; /* batchnum the system is working on. Mismatch + * with rcu_ctrlblk.cur means reinitialize + * outstanding to all groups with active cpus + */ + unsigned long outstanding[RCU_GROUPMASKLEN]; + struct rcu_group_state groups[RCU_GROUPCOUNT]; +#else cpumask_t cpumask; /* CPUs that need to switch in order */ /* for current batch to proceed. */ +#endif }; -struct rcu_state rcu_state ____cacheline_maxaligned_in_smp = - {.lock = SPIN_LOCK_UNLOCKED, .cpumask = CPU_MASK_NONE }; -struct rcu_state rcu_bh_state ____cacheline_maxaligned_in_smp = - {.lock = SPIN_LOCK_UNLOCKED, .cpumask = CPU_MASK_NONE }; +#ifdef RCU_HUGE +#define RCU_STATE_INITIALIZER \ + { \ + .lock = SPIN_LOCK_UNLOCKED, \ + .batchnum = -400, \ + .groups = { [0 ... RCU_GROUPCOUNT-1] = \ + { .lock = SPIN_LOCK_UNLOCKED, .batchnum = -400 } } \ + } + +#else +#define RCU_STATE_INITIALIZER {.lock = SPIN_LOCK_UNLOCKED, .cpumask = CPU_MASK_NONE } +#endif + +struct rcu_state rcu_state ____cacheline_maxaligned_in_smp = RCU_STATE_INITIALIZER; +struct rcu_state rcu_bh_state ____cacheline_maxaligned_in_smp = RCU_STATE_INITIALIZER; DEFINE_PER_CPU(struct rcu_data, rcu_data) = { 0L }; DEFINE_PER_CPU(struct rcu_data, rcu_bh_data) = { 0L }; @@ -223,8 +265,15 @@ if (rcp->next_pending && rcp->completed == rcp->cur) { +#ifdef RCU_HUGE + /* Nothing to do: RCU_HUGE uses lazy initialization of the + * outstanding bitmap + */ +#else + /* FIXME: what does this comment mean? */ /* Can't change, since spin lock held. */ cpus_andnot(rsp->cpumask, cpu_online_map, nohz_cpu_mask); +#endif write_seqcount_begin(&rcp->lock); rcp->next_pending = 0; rcp->cur++; @@ -237,6 +286,76 @@ * Clear it from the cpu mask and complete the grace period if it was the last * cpu. Start another grace period if someone has further entries pending */ +#ifdef RCU_HUGE +static void cpu_quiet(int cpu, struct rcu_ctrlblk *rcp, struct rcu_state *rsp, + struct rcu_data *rdp, int force) +{ + struct rcu_group_state *rgs; + long batch; + int i; + + batch = rcp->cur; + + rgs = &rsp->groups[cpu/RCU_GROUP_SIZE]; + + spin_lock(&rgs->lock); + if (rgs->batchnum != batch) { + int offset; + /* first call for this batch - initialize outstanding */ + rgs->batchnum = batch; + memset(rgs->outstanding, 0, sizeof(rgs->outstanding)); + offset = (cpu/RCU_GROUP_SIZE)*RCU_GROUP_SIZE; + for (i=0;i<RCU_GROUP_SIZE;i++) { + if (cpu_online(i+offset) && !cpu_isset(i+offset, nohz_cpu_mask)) + __set_bit(i, rgs->outstanding); + } + } + if (unlikely(rdp->quiescbatch != rgs->batchnum) && likely(!force)) + goto out_unlock_group; + + __clear_bit(cpu%RCU_GROUP_SIZE, rgs->outstanding); + for (i=0;i<RCU_GROUP_CPUMASKLEN;i++) { + if (rgs->outstanding[i]) + break; + } + if (i==RCU_GROUP_CPUMASKLEN) { + /* group completed, escalate to global level */ + spin_lock(&rsp->lock); + + if (rsp->batchnum != rcp->cur) { + /* first call for this batch - initialize outstanding */ + rsp->batchnum = rcp->cur; + memset(rsp->outstanding, 0, sizeof(rsp->outstanding)); + + for (i=0;i<NR_CPUS;i+=RCU_GROUP_SIZE) { + int j; + for (j=0;j<RCU_GROUP_SIZE;j++) { + if (cpu_online(i+j) && !cpu_isset(i+j, nohz_cpu_mask)) + break; + } + if (j != RCU_GROUP_SIZE) + __set_bit(i/RCU_GROUP_SIZE, rsp->outstanding); + } + } + if (unlikely(rgs->batchnum != rsp->batchnum) && likely(!force)) + goto out_unlock_all; + __clear_bit(cpu/RCU_GROUP_SIZE, rsp->outstanding); + for (i=0;i<RCU_GROUPMASKLEN;i++) { + if (rsp->outstanding[i]) + break; + } + if (i==RCU_GROUPMASKLEN) { + /* all groups completed, batch completed */ + rcp->completed = rcp->cur; + rcu_start_batch(rcp, rsp, 0); + } +out_unlock_all: + spin_unlock(&rcu_state.lock); + } +out_unlock_group: + spin_unlock(&rgs->lock); +} +#else static void cpu_quiet(int cpu, struct rcu_ctrlblk *rcp, struct rcu_state *rsp, struct rcu_data *rdp, int force) { @@ -261,6 +380,7 @@ spin_unlock(&rsp->lock); } +#endif /* * Check if the cpu has gone through a quiescent state (say context @@ -418,8 +538,25 @@ tasklet_schedule(&per_cpu(rcu_tasklet, cpu)); } +#ifdef RCU_HUGE +static void rcu_update_group(int cpu, struct rcu_ctrlblk *rcp, + struct rcu_state *rsp) +{ + int i, offset; + offset = (cpu/RCU_GROUP_SIZE)*RCU_GROUP_SIZE; + for (i=0;i<RCU_GROUP_SIZE;i++) { + if (cpu_online(i+offset) && !cpu_isset(i, nohz_cpu_mask)) + break; + } + if (i == RCU_GROUP_SIZE) { + /* No cpu online from this group. Initialize batchnum. */ + rsp->groups[cpu/RCU_GROUP_SIZE].batchnum = rcp->completed; + } +} +#endif + static void rcu_init_percpu_data(int cpu, struct rcu_ctrlblk *rcp, - struct rcu_data *rdp) + struct rcu_state *rsp, struct rcu_data *rdp) { memset(rdp, 0, sizeof(*rdp)); rdp->curtail = &rdp->curlist; @@ -428,6 +565,9 @@ rdp->quiescbatch = rcp->completed; rdp->qs_pending = 0; rdp->cpu = cpu; +#ifdef RCU_HUGE + rcu_update_group(cpu, rcp, rsp); +#endif } static void __devinit rcu_online_cpu(int cpu) @@ -435,8 +575,8 @@ struct rcu_data *rdp = &per_cpu(rcu_data, cpu); struct rcu_data *bh_rdp = &per_cpu(rcu_bh_data, cpu); - rcu_init_percpu_data(cpu, &rcu_ctrlblk, rdp); - rcu_init_percpu_data(cpu, &rcu_bh_ctrlblk, bh_rdp); + rcu_init_percpu_data(cpu, &rcu_ctrlblk, &rcu_state, rdp); + rcu_init_percpu_data(cpu, &rcu_bh_ctrlblk, &rcu_bh_state, bh_rdp); tasklet_init(&per_cpu(rcu_tasklet, cpu), rcu_process_callbacks, 0UL); } ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-20 20:19 ` Manfred Spraul @ 2004-08-23 21:23 ` Jesse Barnes 2004-08-23 23:13 ` Jesse Barnes 2004-09-10 19:01 ` Greg Edwards 1 sibling, 1 reply; 35+ messages in thread From: Jesse Barnes @ 2004-08-23 21:23 UTC (permalink / raw) To: Manfred Spraul; +Cc: paulmck, Martin J. Bligh, hawkes, linux-kernel, wli On Friday, August 20, 2004 1:19 pm, Manfred Spraul wrote: > Jesse Barnes wrote: > >Looks like a bit more context has changed. Manfred, care to respin > > against -mm3 so I can test? > > The patches are attached. Just boot-tested on a single-cpu system. > > Three changes: > - I've placed the per-group structure into rcu_state. That's simpler but > wrong: the state should be allocated from node-local memory, not a big > global array. > - I found a bug/race in the cpu_offline path: When the last cpu of a > group goes offline then the group must be forced into quiescent state. > The "&& (!forced)" was missing. > - I've removed the spin_unlock_wait(). It was intended to synchronize > cpu_online_mask changes with the calculation of ->outstanding. Paul > convinced me that this is not necessary. I haven't been able to boot successfully with this patch applied. Things seem to get real slow around the time init starts, and the system becomes unusable. I applied them on top of stock 2.6.8.1-mm4, which boots fine without them (testing that again to make sure, but I booted it a few times this morning w/o incident). Jesse ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-23 21:23 ` Jesse Barnes @ 2004-08-23 23:13 ` Jesse Barnes 0 siblings, 0 replies; 35+ messages in thread From: Jesse Barnes @ 2004-08-23 23:13 UTC (permalink / raw) To: Manfred Spraul; +Cc: paulmck, Martin J. Bligh, hawkes, linux-kernel, wli On Monday, August 23, 2004 2:23 pm, Jesse Barnes wrote: > I haven't been able to boot successfully with this patch applied. Things > seem to get real slow around the time init starts, and the system becomes > unusable. I applied them on top of stock 2.6.8.1-mm4, which boots fine > without them (testing that again to make sure, but I booted it a few times > this morning w/o incident). Disregard this. My hardware appears broken, so I can't be sure what's going on. Ugg. Jesse ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-20 20:19 ` Manfred Spraul 2004-08-23 21:23 ` Jesse Barnes @ 2004-09-10 19:01 ` Greg Edwards 2004-09-13 18:21 ` Manfred Spraul 1 sibling, 1 reply; 35+ messages in thread From: Greg Edwards @ 2004-09-10 19:01 UTC (permalink / raw) To: Manfred Spraul Cc: Jesse Barnes, paulmck, Martin J. Bligh, hawkes, linux-kernel, wli On Fri, Aug 20, 2004 at 10:19:26PM +0200, Manfred Spraul wrote: | Jesse Barnes wrote: | | >Looks like a bit more context has changed. Manfred, care to respin | >against -mm3 so I can test? | > | > | > | The patches are attached. Just boot-tested on a single-cpu system. | | Three changes: | - I've placed the per-group structure into rcu_state. That's simpler but | wrong: the state should be allocated from node-local memory, not a big | global array. | - I found a bug/race in the cpu_offline path: When the last cpu of a | group goes offline then the group must be forced into quiescent state. | The "&& (!forced)" was missing. | - I've removed the spin_unlock_wait(). It was intended to synchronize | cpu_online_mask changes with the calculation of ->outstanding. Paul | convinced me that this is not necessary. Manfred, I just tried these patches against 2.6.9-rc1-mm3, on a 2p box, and I'm getting intermittent hangs, either during bootup or shortly after reaching multi-user. In all cases, one of the processes is stuck on rcu_bh_state: [0]kdb> bt Stack traceback for pid 0 0xa000000100970000 0 0 1 0 I 0xa000000100970430 *swapper 0xa0000001000090b0 ia64_spinlock_contention_pre3_4+0x30 args (0xa0000001009f7000, 0xa0000001001017e0, 0x288) r31 (spinlock address) 0xa0000001009f7000 rcu_bh_state 0xa00000010010e100 _metered_spin_lock+0x40 0xa0000001001017e0 __rcu_process_callbacks+0x260 args (0xa0000001009eef00, 0xa0000001009f7000, 0xe000003004a07f70, 0xa0000001000debe0, 0x50d) 0xa0000001000debe0 tasklet_action+0x1c0 args (0xe000003004a07fe8, 0x0, 0xffffffffffff5e10, 0xffffffffffff0020, 0xffffffffffff0028) 0xa0000001000de290 __do_softirq+0x250 args (0xa000000100977bc0, 0x0, 0x1, 0xa000000100d8e2d0, 0x20000001) 0xa0000001000de360 do_softirq+0x80 args (0xef, 0xa000000100977bc0, 0xa000000100d8e2d0, 0xa00000010098b780, 0xa0000001009b5958) 0xa000000100019030 ia64_handle_irq+0x190 args (0xf, 0xa000000100977bc0, 0x0, 0x0, 0xfd) 0xa000000100012300 ia64_leave_kernel args (0xf, 0xa000000100977bc0) 0xa000000100019840 ia64_save_scratch_fpregs+0x20 args (0xa000000100977dd0) 0xa00000010001ad20 default_idle+0xc0 args (0x1, 0xa000000100ba5fe4, 0xa000000100977db0, 0xa000000100977e28, 0xa000000100977e20) 0xa00000010001afe0 cpu_idle+0x1e0 args (0xa000000100d8e2d0, 0xa0000001009024e0, 0xa0000001009024e8, 0xa0000001009059b0, 0xa0000001009059b8) 0xa0000001000095c0 rest_init+0xa0 args (0xa0000001009190b0, 0x590) 0xa0000001009190b0 start_kernel+0x510 args (0x307bd8ac08, 0xd13, 0x3004a3e240, 0x300485da80, 0x307bd31b30) 0xa000000100008590 _start+0x270 args (0x307bd8ac08, 0x307bd5b398, 0x3004a3e270, 0x307bd1f008, 0x30045b2e60) If I'm reading this right, this corresponds to (kernel/rcupdate.c): 507 if (!next_pending) { 508 /* and start it/schedule start if it's a new batch */ 509 spin_lock(&rsp->lock); <---- here 510 rcu_start_batch(rcp, rsp, 1); 511 spin_unlock(&rsp->lock); 512 } Whenever this happens, there is another thread waiting to sync buffers (sometimes with several backed up behind him). It was kjournald in this case. Have you seen this ever with these patches? Regards, Greg Edwards ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-09-10 19:01 ` Greg Edwards @ 2004-09-13 18:21 ` Manfred Spraul 2004-09-14 17:52 ` Greg Edwards 0 siblings, 1 reply; 35+ messages in thread From: Manfred Spraul @ 2004-09-13 18:21 UTC (permalink / raw) To: Greg Edwards Cc: Jesse Barnes, paulmck, Martin J. Bligh, hawkes, linux-kernel, wli Greg Edwards wrote: >Whenever this happens, there is another thread waiting to sync buffers >(sometimes with several backed up behind him). It was kjournald in this >case. Have you seen this ever with these patches? > > > No - as I wrote, I tested only with qemu, without networking. Thus the bh queue was never used. Just booting a complete system with uniprocessor, spinlock debugging enabled immediately showed a bug in line 315: It unlocked rcu_state.lock instead of rsp->lock :-( pseudo-patch: out_unlock_all: - spin_unlock(&rcu_state.lock); + spin_unlock(&rsp->lock); } -- Manfred ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-09-13 18:21 ` Manfred Spraul @ 2004-09-14 17:52 ` Greg Edwards 2004-09-14 18:16 ` Manfred Spraul 0 siblings, 1 reply; 35+ messages in thread From: Greg Edwards @ 2004-09-14 17:52 UTC (permalink / raw) To: Manfred Spraul Cc: Jesse Barnes, paulmck, Martin J. Bligh, hawkes, linux-kernel, wli [-- Attachment #1: Type: text/plain, Size: 199 bytes --] Manfred, Lockstat output attached from 2.6.9-rc2 at 512p and 2.6.9-rc2 + your two remaining RCU patches at 512p. kernbench was run without any arguments. The difference for RCU looks great. Greg [-- Attachment #2: lockstat-2.6.9-rc2.txt --] [-- Type: text/plain, Size: 42426 bytes --] ___________________________________________________________________________________________ System: Linux ascender 2.6.9-rc2 #1 SMP Tue Sep 14 11:05:18 CDT 2004 ia64 Total counts All (512) CPUs Start time: Tue Sep 14 12:04:25 2004 End time: Tue Sep 14 12:10:51 2004 Delta Time: 386.62 sec. Hash table slots in use: 350. Global read lock slots in use: 612. - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - SPINLOCKS HOLD WAIT UTIL CON MEAN( MAX ) MEAN( MAX )(% CPU) TOTAL NOWAIT SPIN RJECT NAME 0.57% 2.4us( 67ms) 41ms( 86ms)(26.7%) 227047021 99.4% 0.57% 0.00% *TOTAL* 0.00% 0% 0.3us( 134us) 0us 46295 100% 0% 0% [0xe00000b003726dd0] 0.00% 0% 0.0us( 0.0us) 0us 1 100% 0% 0% xfs_log_move_tail+0x310 0.00% 0% 0.9us( 16us) 0us 90 100% 0% 0% xfs_log_need_covered+0x100 0.00% 0% 0.1us( 11us) 0us 4988 100% 0% 0% xfs_log_notify+0x40 0.00% 0% 4.8us( 38us) 0us 238 100% 0% 0% xlog_state_do_callback+0x40 0.00% 0% 0.0us( 0.1us) 0us 238 100% 0% 0% xlog_state_do_callback+0x210 0.00% 0% 4.2us( 134us) 0us 238 100% 0% 0% xlog_state_do_callback+0x300 0.00% 0% 0.2us( 5.8us) 0us 239 100% 0% 0% xlog_state_done_syncing+0x40 0.00% 0% 0.5us( 43us) 0us 10111 100% 0% 0% xlog_state_get_iclog_space+0x30 0.00% 0% 0.2us( 6.7us) 0us 4757 100% 0% 0% xlog_state_put_ticket+0x20 0.00% 0% 0.1us( 17us) 0us 10212 100% 0% 0% xlog_state_release_iclog+0x50 0.00% 0% 2.6us( 37us) 0us 148 100% 0% 0% xlog_state_sync_all+0x30 0.00% 0% 0.2us( 6.7us) 0us 66 100% 0% 0% xlog_state_sync_all+0x440 0.00% 0% 4.6us( 16us) 0us 46 100% 0% 0% xlog_state_sync+0x40 0.00% 0% 0.9us( 7.0us) 0us 35 100% 0% 0% xlog_state_sync+0x3f0 0.00% 0% 0.4us( 7.2us) 0us 21 100% 0% 0% xlog_state_want_sync+0x20 0.00% 0% 0.5us( 18us) 0us 4757 100% 0% 0% xlog_ticket_get+0x50 0.00% 0% 0.1us( 34us) 0us 9974 100% 0% 0% xlog_write+0x5f0 0.00% 0% 0.8us( 6.8us) 0us 21 100% 0% 0% xlog_write+0x6c0 0.00% 0% 0.4us( 15us) 0us 115 100% 0% 0% xlog_write+0x800 0.00% 0% 0.2us( 64us) 0us 43424 100% 0% 0% [0xe00000b003726e70] 0.00% 0% 0.1us( 16us) 0us 14949 100% 0% 0% xfs_log_move_tail+0x70 0.00% 0% 0.0us( 8.0us) 0us 10212 100% 0% 0% xlog_assign_tail_lsn+0x50 0.00% 0% 1.0us( 64us) 0us 4757 100% 0% 0% xlog_grant_log_space+0x40 0.00% 0% 0.2us( 19us) 0us 6588 100% 0% 0% xlog_grant_push_ail+0x50 0.00% 0% 0.1us( 7.9us) 0us 1831 100% 0% 0% xlog_regrant_reserve_log_space+0x50 0.00% 0% 3.7us( 16us) 0us 92 100% 0% 0% xlog_regrant_write_log_space+0x90 0.00% 0% 0.1us( 6.5us) 0us 238 100% 0% 0% xlog_state_do_callback+0x1c0 0.00% 0% 0.3us( 17us) 0us 4757 100% 0% 0% xlog_ungrant_log_space+0x50 0% 0% 0us 1 100% 0% 0% [0xe000023003875d80] 0% 0% 0us 1 100% 0% 0% credit_entropy_store+0x40 0% 0% 0us 8849 100% 0% 0% [0xe00005b00387a080] 0% 0% 0us 8849 100% 0% 0% sn_dma_flush+0x1e0 0% 0% 0us 8849 100% 0% 0% [0xe00006307b8f2018] 0% 0% 0us 8849 100% 0% 0% scsi_put_command+0xe0 0.04% 0.28% 3.5us( 90us) 16us( 91us)(0.00%) 44253 99.7% 0.28% 0% [0xe00006307b8f2040] 0.04% 0.16% 17us( 90us) 19us( 50us)(0.00%) 8857 99.8% 0.16% 0% qla1280_intr_handler+0x30 0.00% 0.31% 0.3us( 30us) 4.6us( 15us)(0.00%) 8849 99.7% 0.31% 0% scsi_device_unbusy+0x50 0% 0.29% 9.3us( 85us)(0.00%) 8849 99.7% 0.29% 0% scsi_dispatch_cmd+0x340 0% 0.44% 21us( 91us)(0.00%) 8849 99.6% 0.44% 0% scsi_request_fn+0x2d0 0% 0.20% 31us( 87us)(0.00%) 8849 99.8% 0.20% 0% scsi_run_queue+0xa0 0.00% 0.10% 0.1us( 67us) 10us( 44us)(0.00%) 40574 99.9% 0.10% 0% [0xe00008b003eb7024] 0.00% 0% 0.2us( 7.3us) 0us 442 100% 0% 0% xfs_buf_iodone+0x30 0.00% 0% 0.2us( 4.2us) 0us 47 100% 0% 0% xfs_buf_item_unpin+0x160 0.00% 0% 0.1us( 2.6us) 0us 138 100% 0% 0% xfs_efi_item_unpin+0x30 0.00% 0% 0.2us( 12us) 0us 138 100% 0% 0% xfs_efi_release+0x30 0.00% 0% 0.1us( 4.6us) 0us 3901 100% 0% 0% xfs_iflush_done+0xc0 0.00% 0.97% 0.2us( 30us) 10us( 44us)(0.00%) 3903 99.0% 0.97% 0% xfs_iflush_int+0x430 0.00% 0.01% 0.1us( 67us) 2.4us( 2.9us)(0.00%) 19342 100% 0.01% 0% xfs_trans_chunk_committed+0x210 0.00% 0% 32us( 32us) 0us 1 100% 0% 0% xfs_trans_push_ail+0x40 0.00% 0% 0.5us( 21us) 0us 2450 100% 0% 0% xfs_trans_push_ail+0x2c0 0.00% 0.01% 0.1us( 16us) 24us( 24us)(0.00%) 10212 100% 0.01% 0% xfs_trans_tail_ail+0x20 0.00% 0% 0.3us( 55us) 0us 13977 100% 0% 0% [0xe00008b003eb7110] 0.00% 0% 0.3us( 55us) 0us 10099 100% 0% 0% xfs_mod_incore_sb+0x20 0.00% 0% 0.1us( 23us) 0us 3878 100% 0% 0% xfs_mod_incore_sb_batch+0x30 0.01% 0.38% 0.3us( 474us) 14us( 246us)(0.00%) 139387 99.6% 0.38% 0% [0xe00009b003cbf034] 0% 0.24% 13us( 79us)(0.00%) 8212 99.8% 0.24% 0% __cfq_get_queue+0x1f0 0% 0.66% 18us( 203us)(0.00%) 19020 99.3% 0.66% 0% __make_request+0x150 0.00% 0.45% 0.0us( 36us) 11us( 50us)(0.00%) 8849 99.5% 0.45% 0% blk_run_queue+0x40 0% 0.33% 10us( 75us)(0.00%) 17061 99.7% 0.33% 0% cfq_get_queue+0x50 0.01% 0.32% 2.6us( 474us) 18us( 187us)(0.00%) 17382 99.7% 0.32% 0% generic_unplug_device+0x40 0% 0.27% 7.6us( 91us)(0.00%) 17061 99.7% 0.27% 0% get_request+0x80 0% 0.33% 7.2us( 31us)(0.00%) 8212 99.7% 0.33% 0% get_request+0x4d0 0% 0.18% 28us( 216us)(0.00%) 8849 99.8% 0.18% 0% scsi_device_unbusy+0xb0 0% 0.18% 25us( 120us)(0.00%) 8849 99.8% 0.18% 0% scsi_end_request+0x160 0.00% 1.2% 0.1us( 48us) 12us( 246us)(0.00%) 8849 98.8% 1.2% 0% scsi_request_fn+0x520 0% 0.15% 6.5us( 17us)(0.00%) 17043 99.8% 0.15% 0% scsi_request_fn+0x5b0 0.00% 0% 0.0us( 0.3us) 0us 17698 100% 0% 0% [0xe00009b003cbf038] 0% 0% 0us 8849 100% 0% 0% scsi_get_command+0x110 0.00% 0% 0.1us( 0.3us) 0us 8849 100% 0% 0% scsi_put_command+0x70 0.00% 0% 0.1us( 2.5us) 0us 78 100% 0% 0% [0xe0001330032bb504] 0.00% 0% 0.1us( 2.5us) 0us 78 100% 0% 0% do_select+0x60 0% 0% 0us 96 100% 0% 0% [0xe00039b003d50380] 0% 0% 0us 65 100% 0% 0% qla2x00_intr_handler+0x70 0% 0% 0us 31 100% 0% 0% qla2x00_mailbox_command+0xe0 0% 0% 0us 67 100% 0% 0% [0xe00039b003d52480] 0% 0% 0us 65 100% 0% 0% qla2x00_next+0x80 0% 0% 0us 1 100% 0% 0% qla2x00_restart_queues+0x120 0% 0% 0us 1 100% 0% 0% qla2x00_restart_queues+0x390 0% 0% 0us 93 100% 0% 0% [0xe00039b003d54478] 0% 0% 0us 31 100% 0% 0% qla2x00_intr_handler+0x4e0 0% 0% 0us 31 100% 0% 0% qla2x00_mailbox_command+0x9c0 0% 0% 0us 31 100% 0% 0% qla2x00_mailbox_command+0xba0 0.00% 0% 0.3us( 3.0us) 0us 14 100% 0% 0% [0xe0004a3079d2d930] 0.00% 0% 0.3us( 3.0us) 0us 14 100% 0% 0% unmap_mapping_range+0xc0 0% 0% 0us 4 100% 0% 0% [0xe0004db003d47e18] 0% 0% 0us 2 100% 0% 0% __down_interruptible+0xc0 0% 0% 0us 2 100% 0% 0% __down_interruptible+0x240 0.00% 0% 27us( 369us) 0us 16 100% 0% 0% [0xe000603003bd634c] 0.00% 0% 0.3us( 1.5us) 0us 8 100% 0% 0% rwsem_down_read_failed+0x60 0.00% 0% 53us( 369us) 0us 8 100% 0% 0% rwsem_wake+0x30 0.00% 0% 251us( 251us) 0us 1 100% 0% 0% [0xe00071b07882b6e8] 0.00% 0% 251us( 251us) 0us 1 100% 0% 0% unmap_vmas+0x540 0% 0% 0us 3 100% 0% 0% batch_lock 0% 0% 0us 3 100% 0% 0% batch_entropy_store+0x80 0.01% 0.32% 10us( 85us) 63us( 169us)(0.00%) 3152 99.7% 0.32% 0% bdev_lock 0.01% 0.32% 10us( 85us) 63us( 169us)(0.00%) 3152 99.7% 0.32% 0% nr_blockdev_pages+0x20 0.03% 0.01% 4.9us( 64ms) 94us( 94us)(0.00%) 19863 100% 0.01% 0% cdev_lock 0.03% 0.01% 4.9us( 64ms) 94us( 94us)(0.00%) 19863 100% 0.01% 0% chrdev_open+0x40 0.01% 0% 47us( 582us) 0us 512 100% 0% 0% cpe_history_lock.4 0.01% 0% 47us( 582us) 0us 512 100% 0% 0% ia64_mca_cpe_int_handler+0xa0 0.10% 0.04% 0.2us( 29ms) 6.0us( 68us)(0.00%) 2646492 100% 0.04% 0% dcache_lock 0.00% 0.02% 0.6us( 40us) 3.7us( 5.6us)(0.00%) 9152 100% 0.02% 0% d_alloc+0x260 0.00% 0% 0.4us( 8.5us) 0us 1184 100% 0% 0% d_delete+0x40 0.00% 0.04% 0.1us( 26us) 1.5us( 2.3us)(0.00%) 10353 100% 0.04% 0% d_instantiate+0x50 0.00% 0% 5.2us( 49us) 0us 97 100% 0% 0% d_move+0x60 0.01% 0.07% 20us( 23ms) 12us( 12us)(0.00%) 1341 100% 0.07% 0% d_path+0x110 0.00% 0.04% 0.8us(3300us) 1.2us( 2.3us)(0.00%) 9151 100% 0.04% 0% d_rehash+0xc0 0.00% 0% 0.7us( 3.6us) 0us 6 100% 0% 0% d_splice_alias+0xc0 0.09% 0.04% 0.1us( 29ms) 6.1us( 68us)(0.00%) 2564665 100% 0.04% 0% dput+0x50 0.00% 0% 0.1us( 25us) 0us 24437 100% 0% 0% link_path_walk+0x1000 0.00% 0% 0.1us( 9.5us) 0us 18468 100% 0% 0% link_path_walk+0x1ed0 0.00% 0% 1.5us( 19us) 0us 149 100% 0% 0% proc_pid_unhash+0x50 0.00% 0% 1.7us( 20us) 0us 298 100% 0% 0% prune_dcache+0x50 0.00% 0% 0.0us( 0.1us) 0us 149 100% 0% 0% prune_dcache+0x380 0.00% 0% 0.5us( 8.9us) 0us 447 100% 0% 0% select_parent+0x30 0.01% 0% 3.1us( 78us) 0us 6595 100% 0% 0% sys_getcwd+0x210 0.02% 0.05% 0.1us( 39us) 9.6us( 40us)(0.00%) 516030 100% 0.05% 0% files_lock 0.00% 0.07% 0.1us( 31us) 8.2us( 9.9us)(0.00%) 2812 100% 0.07% 0% check_tty_count+0x20 0.01% 0.06% 0.1us( 28us) 9.9us( 40us)(0.00%) 255906 100% 0.06% 0% file_kill+0x70 0.01% 0.05% 0.2us( 39us) 9.3us( 32us)(0.00%) 257312 100% 0.05% 0% file_move+0x40 0% 0% 0us 252 100% 0% 0% filp_count_lock 0% 0% 0us 189 100% 0% 0% filp_ctor+0x70 0% 0% 0us 63 100% 0% 0% filp_dtor+0x40 0% 0.01% 5.8us( 9.8us)(0.00%) 91110 100% 0.01% 0% ia64_ctx 0% 0.02% 5.0us( 7.1us)(0.00%) 29917 100% 0.02% 0% exec_mmap+0x4f0 0% 0.00% 9.8us( 9.8us)(0.00%) 20988 100% 0.00% 0% schedule+0xde0 0% 0% 0us 40205 100% 0% 0% smp_flush_tlb_mm+0x310 0% 0% 0us 512 100% 0% 0% ia64_state_log+0x60 0% 0% 0us 512 100% 0% 0% ia64_log_get+0x80 0.00% 0% 0.6us( 1.4us) 0us 3 100% 0% 0% inet_peer_unused_lock 0.00% 0% 0.6us( 1.4us) 0us 3 100% 0% 0% cleanup_once+0x60 0.10% 0.09% 1.2us( 173us) 36us( 514us)(0.00%) 314539 100% 0.09% 0% inode_lock 0.00% 0.06% 0.4us( 44us) 19us( 92us)(0.00%) 47856 100% 0.06% 0% __mark_inode_dirty+0xf0 0.02% 0.22% 1.2us( 132us) 55us( 514us)(0.00%) 74226 99.8% 0.22% 0% __sync_single_inode+0x100 0.00% 0% 12us( 12us) 0us 1 100% 0% 0% __wait_on_freeing_inode+0x170 0.00% 0% 0.1us( 8.9us) 0us 4761 100% 0% 0% generic_delete_inode+0x1f0 0.00% 0.07% 1.1us( 24us) 6.1us( 7.3us)(0.00%) 4597 100% 0.07% 0% get_new_inode_fast+0x50 0.00% 0.15% 1.6us( 40us) 31us( 68us)(0.00%) 4597 99.8% 0.15% 0% iget_locked+0xb0 0.00% 0.03% 0.1us( 21us) 7.3us( 9.8us)(0.00%) 6259 100% 0.03% 0% igrab+0x20 0.01% 0.04% 0.3us( 72us) 8.7us( 30us)(0.00%) 91317 100% 0.04% 0% iput+0xa0 0.00% 0.15% 0.4us( 20us) 9.2us( 20us)(0.00%) 4710 99.9% 0.15% 0% new_inode+0x70 0.00% 1.2% 0.7us( 99us) 5.5us( 12us)(0.00%) 810 98.8% 1.2% 0% sync_inodes_sb+0x140 0.06% 0.04% 3.0us( 173us) 5.3us( 26us)(0.00%) 74701 100% 0.04% 0% sync_sb_inodes+0x630 0.00% 0.14% 3.0us( 107us) 0.4us( 0.4us)(0.00%) 704 99.9% 0.14% 0% writeback_inodes+0x20 0.09% 0.03% 9.0us(1040us) 163us( 631us)(0.00%) 37441 100% 0.03% 0% kernel_flag 0.02% 0.03% 4.5us( 415us) 226us( 631us)(0.00%) 19863 100% 0.03% 0% chrdev_open+0x1e0 0.00% 0.06% 0.3us( 20us) 61us( 85us)(0.00%) 3279 100% 0.06% 0% de_put+0x50 0.00% 0% 0.1us( 0.1us) 0us 696 100% 0% 0% linvfs_ioctl+0x140 0.04% 0.03% 48us(1040us) 40us( 40us)(0.00%) 3429 100% 0.03% 0% proc_lookup+0x60 0.00% 0% 37us( 37us) 0us 1 100% 0% 0% schedule+0xc20 0.00% 0% 3.8us( 224us) 0us 2121 100% 0% 0% sys_ioctl+0xa0 0.01% 0% 3.5us( 139us) 0us 6592 100% 0% 0% sys_sysctl+0xd0 0.01% 0.28% 26us( 266us) 150us( 290us)(0.00%) 1406 99.7% 0.28% 0% tty_release+0x50 0.00% 0% 257us( 706us) 0us 54 100% 0% 0% tty_write+0x440 0% 0% 0us 7 100% 0% 0% logbuf_lock 0% 0% 0us 5 100% 0% 0% release_console_sem+0x50 0% 0% 0us 2 100% 0% 0% vprintk+0x60 0.01% 0.15% 0.4us(7663us) 10us( 31us)(0.00%) 110845 99.9% 0.15% 0% mmlist_lock 0.00% 0.04% 0.1us( 15us) 5.0us( 14us)(0.00%) 20988 100% 0.04% 0% copy_mm+0x2a0 0.01% 0.05% 0.8us( 24us) 15us( 29us)(0.00%) 29917 100% 0.05% 0% exec_mmap+0x40 0.01% 0.24% 0.3us(7663us) 10us( 31us)(0.00%) 59940 99.8% 0.24% 0% mmput+0x30 0% 0% 0us 1051 100% 0% 0% page_uptodate_lock.1 0% 0% 0us 1051 100% 0% 0% end_buffer_async_write+0xc0 0.00% 0.01% 0.3us( 75us) 0.8us( 0.8us)(0.00%) 9500 100% 0.01% 0% pbd_delwrite_lock 0.00% 0% 7.0us( 75us) 0us 383 100% 0% 0% pagebuf_daemon+0x200 0.00% 0.01% 0.1us( 12us) 0.8us( 0.8us)(0.00%) 8618 100% 0.01% 0% pagebuf_delwri_dequeue+0x30 0.00% 0% 0.3us( 19us) 0us 499 100% 0% 0% pagebuf_delwri_queue+0x30 0% 0% 0us 276 100% 0% 0% pdflush_lock 0% 0% 0us 92 100% 0% 0% __pdflush+0x220 0% 0% 0us 92 100% 0% 0% __pdflush+0x320 0% 0% 0us 92 100% 0% 0% pdflush_operation+0x60 26.8% 89.9% 73us( 13ms) 41ms( 86ms)(26.7%) 1418535 10.1% 89.9% 0% rcu_state 0.01% 16.5% 17us(1146us) 9116us( 66ms)(0.00%) 2790 83.5% 16.5% 0% __rcu_process_callbacks+0x260 26.8% 90.1% 73us( 13ms) 41ms( 86ms)(26.7%) 1415745 9.9% 90.1% 0% rcu_check_quiescent_state+0xf0 0.00% 0% 0.9us( 6.9us) 0us 54 100% 0% 0% redirect_lock 0.00% 0% 0.9us( 6.9us) 0us 54 100% 0% 0% redirected_tty_write+0x30 0.00% 0% 3.9us( 46us) 0us 97 100% 0% 0% rename_lock+0x4 0.00% 0% 3.9us( 46us) 0us 97 100% 0% 0% d_move+0x80 0% 3.8% 78us( 259us)(0.00%) 629 96.2% 3.8% 0% sal_console_port+0x40 0% 0% 0us 2 100% 0% 0% sn_sal_console_write+0x380 0% 7.9% 78us( 259us)(0.00%) 303 92.1% 7.9% 0% sn_sal_interrupt+0x200 0% 0% 0us 108 100% 0% 0% uart_put_char+0xa0 0% 0% 0us 162 100% 0% 0% uart_start+0x50 0% 0% 0us 54 100% 0% 0% uart_write+0x400 0.00% 0% 0.9us( 154us) 0us 3471 100% 0% 0% sb_lock 0.00% 0% 0.6us( 51us) 0us 855 100% 0% 0% get_super_to_sync+0x30 0.00% 0% 2.0us( 6.7us) 0us 15 100% 0% 0% get_super_to_sync+0x30 0.00% 0% 0.1us( 16us) 0us 903 100% 0% 0% put_super+0x20 0.00% 0% 6.6us( 92us) 0us 45 100% 0% 0% set_sb_syncing+0x20 0.00% 0% 1.7us( 10us) 0us 30 100% 0% 0% sync_filesystems+0x70 0.00% 0% 1.6us( 46us) 0us 60 100% 0% 0% sync_filesystems+0x170 0.00% 0% 2.5us( 12us) 0us 155 100% 0% 0% sync_supers+0x30 0.00% 0% 0.7us( 36us) 0us 704 100% 0% 0% writeback_inodes+0x40 0.00% 0% 1.5us( 154us) 0us 704 100% 0% 0% writeback_inodes+0x210 0.00% 0% 0.4us( 18us) 0us 3152 100% 0% 0% swaplock 0.00% 0% 0.4us( 18us) 0us 3152 100% 0% 0% si_swapinfo+0x20 0.00% 0% 0.1us( 22us) 0us 30023 100% 0% 0% uidhash_lock 0.00% 0% 0.1us( 22us) 0us 30023 100% 0% 0% free_uid+0x30 0.00% 0.04% 3.1us( 41us) 11us( 13us)(0.00%) 4593 100% 0.04% 0% vfsmount_lock 0.00% 0% 0.1us( 13us) 0us 1192 100% 0% 0% __d_path+0x2b0 0.00% 0.06% 4.2us( 41us) 11us( 13us)(0.00%) 3401 100% 0.06% 0% lookup_mnt+0x80 0.00% 0% 0.5us( 9.6us) 0us 1318 100% 0% 0% vnumber_lock 0.00% 0% 0.5us( 9.6us) 0us 1318 100% 0% 0% vn_initialize+0xd0 0.69% 0% 6.7us(1939us) 0us 395897 100% 0% 0% xtime_lock+0x4 0.69% 0% 6.7us(1939us) 0us 395897 100% 0% 0% timer_interrupt+0x330 0.07% 0.01% 0.2us( 55ms) 8.0us( 273us)(0.00%) 1705215 100% 0.01% 0% __d_lookup+0x190 0% 14.2% 14us( 33us)(0.00%) 353 85.8% 14.2% 0% __down+0x200 0% 3.0% 4.1us( 8.4us)(0.00%) 460 97.0% 3.0% 0% __down+0xc0 0% 0.94% 16us( 98us)(0.00%) 12398 99.1% 0.94% 0% __down_trylock+0x40 0.00% 0% 0.3us( 18us) 0us 30023 100% 0% 0% __exit_signal+0x80 0.00% 0% 0.1us( 23us) 0us 115382 100% 0% 0% __mod_timer+0x120 0% 0% 0us 115382 100% 0% 0% __mod_timer+0xa0 0% 0.07% 2.6us( 53us)(0.00%) 1174525 100% 0.07% 0% __page_cache_release+0x70 0% 0.05% 21us( 21us)(0.00%) 1968 100% 0.05% 0% __pagevec_lru_add+0xe0 0% 0.09% 8.9us( 66us)(0.00%) 195389 100% 0.09% 0% __pagevec_lru_add_active+0xe0 0.01% 0% 0.1us( 21us) 0us 203620 100% 0% 0% __pmd_alloc+0x60 0% 0% 0us 97005 100% 0% 0% __queue_work+0x30 0% 0% 0us 2050 100% 0% 0% __set_page_dirty_nobuffers+0xd0 0% 0.02% 5.9us( 13us)(0.00%) 228098 100% 0.02% 0% __wake_up+0x30 0% 0.00% 6.5us( 6.5us)(0.00%) 30105 100% 0.00% 0% __wake_up_sync+0x50 0.01% 0% 0.9us( 54us) 0us 49332 100% 0% 0% _pagebuf_find+0xd0 0% 0% 0us 25797 100% 0% 0% activate_page+0x70 0% 0% 0us 11 100% 0% 0% add_entropy_words+0xc0 0% 0% 0us 2284 100% 0% 0% add_to_page_cache+0x80 0% 0.00% 3.3us( 3.6us)(0.00%) 146682 100% 0.00% 0% add_wait_queue+0x50 0% 0% 0us 46 100% 0% 0% add_wait_queue_exclusive+0x50 0.00% 0% 0.1us( 23us) 0us 264078 100% 0% 0% anon_vma_link+0x30 0.05% 0% 0.6us( 58ms) 0us 281091 100% 0% 0% anon_vma_prepare+0xc0 0.01% 0.09% 0.1us( 34us) 14us( 48us)(0.00%) 562320 100% 0.09% 0% anon_vma_unlink+0x30 0% 0.02% 10us( 27us)(0.00%) 30023 100% 0.02% 0% buffered_rmqueue+0x3f0 0.02% 0.03% 6.8us( 195us) 15us( 31us)(0.00%) 10608 100% 0.03% 0% cache_alloc_refill+0xb0 0.00% 0.04% 6.5us( 48us) 9.9us( 9.9us)(0.00%) 2544 100% 0.04% 0% cache_flusharray+0x30 0.00% 0% 0.1us( 10us) 0us 646 100% 0% 0% cache_grow+0x260 0.00% 0% 0.9us( 12us) 0us 646 100% 0% 0% cache_grow+0xf0 0% 0.00% 12us( 67us)(0.00%) 9825514 100% 0.00% 0% cache_reap+0x230 0% 0% 0us 572 100% 0% 0% cache_reap+0x430 0.01% 0% 1.0us( 39us) 0us 42316 100% 0% 0% change_protection+0x90 0% 0% 0us 29157 100% 0% 0% complete+0x40 0.00% 0% 0.4us( 49us) 0us 29917 100% 0% 0% compute_creds+0x20 0.02% 0% 2.8us(8472us) 0us 30023 100% 0% 0% copy_files+0x1c0 0.00% 0% 0.1us( 16us) 0us 17408 100% 0% 0% copy_files+0x200 0.05% 0% 10us( 61ms) 0us 17408 100% 0% 0% copy_files+0x2c0 0.01% 0.01% 0.1us( 30us) 1696us( 29ms)(0.00%) 362934 100% 0.01% 0% copy_mm+0x5a0 0.77% 0% 5.9us( 67ms) 0us 506486 100% 0% 0% copy_mm+0x5e0 1.1% 0% 9.1us( 67ms) 0us 485498 100% 0% 0% copy_page_range+0x2a0 0.00% 0% 0.5us( 23us) 0us 2050 100% 0% 0% create_empty_buffers+0xa0 0.00% 0% 0.1us( 3.1us) 0us 1184 100% 0% 0% d_delete+0x50 0.00% 0% 2.5us( 19us) 0us 97 100% 0% 0% d_move+0x100 0.00% 0% 3.0us( 19us) 0us 44 100% 0% 0% d_move+0x560 0.00% 0% 2.7us( 17us) 0us 53 100% 0% 0% d_move+0xe0 0.00% 0% 0.1us( 4.7us) 0us 9151 100% 0% 0% d_rehash+0xd0 0% 0.00% 2.0us( 2.0us)(0.00%) 25856 100% 0.00% 0% del_timer+0x80 0.02% 0.02% 0.5us( 46ms) 6.0us( 20us)(0.00%) 179791 100% 0.02% 0% deny_write_access+0x40 0.00% 0% 0.1us( 20us) 0us 46631 100% 0% 0% dnotify_flush+0xa0 0.02% 0.02% 0.3us( 92us) 7.8us( 43us)(0.00%) 330662 100% 0.02% 0% dnotify_parent+0x60 0.00% 0% 0.6us( 23us) 0us 9194 100% 0% 0% do_IRQ+0x1d0 0.00% 0% 0.4us( 23us) 0us 9194 100% 0% 0% do_IRQ+0x2b0 0.03% 0% 0.3us( 105us) 0us 384053 100% 0% 0% do_anonymous_page+0x270 0.00% 0% 0.1us( 16us) 0us 30023 100% 0% 0% do_exit+0x3d0 0.00% 0% 0.0us( 9.4us) 0us 30023 100% 0% 0% do_exit+0x460 0.00% 0% 0.1us( 21us) 0us 30023 100% 0% 0% do_exit+0x4b0 0.00% 0% 0.0us( 2.5us) 0us 30023 100% 0% 0% do_exit+0x6d0 0.00% 0% 0.1us( 8.6us) 0us 933 100% 0% 0% do_fcntl+0xb0 0.12% 0% 3.0us( 50ms) 0us 153060 100% 0% 0% do_munmap+0x220 0.17% 0% 0.3us( 31ms) 0us 2399811 100% 0% 0% do_no_page+0x220 0% 0.02% 22us( 52us)(0.00%) 30023 100% 0.02% 0% do_notify_parent+0x2e0 0% 0.05% 8.1us( 156us)(0.00%) 158742 100% 0.05% 0% do_page_cache_readahead+0x140 0% 0% 0us 296 100% 0% 0% do_page_cache_readahead+0x270 0% 0.00% 3.7us( 4.6us)(0.00%) 283293 100% 0.00% 0% do_sigaction+0x110 0% 0% 0us 36528 100% 0% 0% do_sigaction+0x2a0 0.11% 0% 0.8us( 65ms) 0us 497135 100% 0% 0% do_wp_page+0x2d0 0.01% 2.3% 1.3us( 242us) 0us 26957 97.7% 0% 2.3% double_lock_balance+0x20 0.00% 85.4% 26us( 188us) 445us(6065us)(0.00%) 321 14.6% 85.4% 0% double_lock_balance+0x80 0.00% 43.9% 10us( 534us) 144us(3411us)(0.00%) 626 56.1% 43.9% 0% double_lock_balance+0xa0 0.00% 0% 1.0us( 575us) 0us 12101 100% 0% 0% double_rq_lock+0x40 0.00% 0.13% 0.1us( 4.4us) 270us( 574us)(0.00%) 20122 99.9% 0.13% 0% double_rq_lock+0x60 0.00% 0.25% 0.3us( 25us) 293us( 619us)(0.00%) 8021 99.8% 0.25% 0% double_rq_lock+0x90 0.02% 0.01% 0.2us( 29ms) 10us( 20us)(0.00%) 412261 100% 0.01% 0% dput+0xb0 0.00% 0% 0.8us( 34us) 0us 373 100% 0% 0% dupfd+0x30 0.03% 0% 4.1us( 64ms) 0us 29917 100% 0% 0% exec_mmap+0x110 6.7% 0% 512us( 64ms) 0us 50905 100% 0% 0% exit_mmap+0x50 0.00% 0% 0.3us( 101us) 0us 17660 100% 0% 0% expand_fd_array+0x130 0.00% 0% 0.1us( 4.4us) 0us 252 100% 0% 0% expand_fd_array+0x240 0.00% 0% 1.9us( 23us) 0us 925 100% 0% 0% expand_stack+0x60 0% 0% 0us 2 100% 0% 0% extract_entropy+0xc0 0.00% 0% 0.1us( 15us) 0us 234897 100% 0% 0% fd_install+0x30 0.01% 0% 0.1us( 38us) 0us 438553 100% 0% 0% fget+0x30 0% 0.11% 7.7us( 347us)(0.00%) 2673613 99.9% 0.11% 0% find_get_page+0x40 0% 0% 0us 4235 100% 0% 0% find_get_pages+0x40 0% 0.00% 4.7us( 4.7us)(0.00%) 128465 100% 0.00% 0% find_get_pages_tag+0x40 0% 0.00% 1.3us( 1.3us)(0.00%) 47999 100% 0.00% 0% find_lock_page+0x40 0% 0% 0us 204 100% 0% 0% find_trylock_page+0x40 0% 0.05% 6.9us( 15us)(0.00%) 8255 100% 0.05% 0% finish_wait+0x90 0.00% 0% 0.2us( 39us) 0us 38641 100% 0% 0% flush_old_exec+0x4f0 0% 0.09% 6.4us( 45us)(0.00%) 80146 100% 0.09% 0% force_page_cache_readahead+0x170 0% 0.09% 8.7us( 54us)(0.00%) 245613 100% 0.09% 0% free_pages_bulk+0x90 0% 0.19% 11us( 63us)(0.00%) 27877 99.8% 0.19% 0% get_signal_to_deliver+0x60 0.02% 0% 0.3us( 70us) 0us 281834 100% 0% 0% get_unused_fd+0x40 0.00% 0% 0.1us( 2.8us) 0us 21471 100% 0% 0% get_write_access+0x30 0.24% 0% 0.3us( 60ms) 0us 3599784 100% 0% 0% handle_mm_fault+0x160 0% 0% 0us 27877 100% 0% 0% handle_signal+0x100 0% 0% 0us 27877 100% 0% 0% ia64_rt_sigreturn+0x1b0 0.00% 0% 0.2us( 22us) 0us 29917 100% 0% 0% install_arg_page+0xc0 0% 0% 0us 30038 100% 0% 0% k_getrusage+0x530 0% 0% 0us 356 100% 0% 0% k_getrusage+0xd0 0.00% 0% 0.1us( 0.5us) 0us 696 100% 0% 0% linvfs_ioctl+0xe0 0.00% 9.0% 3.6us( 73us) 314us(3478us)(0.00%) 659 91.0% 9.0% 0% load_balance+0x170 103% 0.00% 9.7us(4462us) 17us( 99us)(0.00%) 41140382 100% 0.00% 0% load_balance+0x30 0% 0% 0us 74225 100% 0% 0% mapping_tagged+0x40 0.00% 0.03% 0.3us(1546us) 89us( 310us)(0.00%) 40373 100% 0.03% 0% migration_thread+0x130 0.00% 0% 1.7us( 19us) 0us 149 100% 0% 0% mounts_open+0xa0 0.00% 0.00% 0.1us( 30us) 25us( 25us)(0.00%) 61530 100% 0.00% 0% pagebuf_rele+0x60 0.00% 0% 0.1us( 0.9us) 0us 149 100% 0% 0% pid_base_iput+0x30 0% 0% 0us 4650 100% 0% 0% prepare_to_wait+0x60 0% 0.01% 3.8us( 3.8us)(0.00%) 8336 100% 0.01% 0% prepare_to_wait_exclusive+0x60 0.00% 0% 0.1us( 6.0us) 0us 149 100% 0% 0% proc_pid_lookup+0x1e0 0.00% 0% 0.9us( 16us) 0us 298 100% 0% 0% prune_dcache+0x130 0.45% 0% 6.8us( 62ms) 0us 254542 100% 0% 0% pte_alloc_map+0x140 0.00% 0% 0.1us( 6.1us) 0us 47310 100% 0% 0% put_unused_fd+0x30 0% 0% 0us 6546 100% 0% 0% qla2x00_timer+0x2c0 0% 0.22% 13us( 21us)(0.00%) 17605 99.8% 0.22% 0% release_pages+0x180 0.17% 0% 22us( 66ms) 0us 30023 100% 0% 0% release_task+0x60 0% 0% 0us 1992 100% 0% 0% remove_from_page_cache+0x70 0.05% 0.21% 0.3us( 60us) 9.7us( 84us)(0.00%) 748151 99.8% 0.21% 0% remove_vm_struct+0x50 0% 0.00% 27us( 27us)(0.00%) 146728 100% 0.00% 0% remove_wait_queue+0x30 0% 0.09% 6.9us( 41us)(0.00%) 221875 100% 0.09% 0% rmqueue_bulk+0x40 0.00% 0% 0.5us( 2.7us) 0us 6 100% 0% 0% rt_check_expire+0xe0 0% 0% 0us 89527 100% 0% 0% run_timer_softirq+0x2c0 0% 0.00% 6.7us( 16us)(0.00%) 145797886 100% 0.00% 0% run_timer_softirq+0xb0 0.11% 1.3% 1.1us(1286us) 2.4us( 251us)(0.00%) 369207 98.7% 1.3% 0% schedule+0x260 0% 0% 0us 363195 100% 0% 0% schedule+0x680 0.03% 0.03% 0.4us( 105us) 27us( 296us)(0.00%) 350681 100% 0.03% 0% scheduler_tick+0x520 0.00% 0% 0.1us( 6.8us) 0us 40135 100% 0% 0% set_close_on_exec+0x30 0.00% 0% 0.2us( 20us) 0us 29917 100% 0% 0% set_task_comm+0x20 0% 0.07% 23us( 61us)(0.00%) 18710 100% 0.07% 0% sigprocmask+0x50 0.01% 0% 0.2us( 12ms) 0us 286514 100% 0% 0% sys_close+0x30 0.00% 0% 0.2us( 48us) 0us 23261 100% 0% 0% sys_dup2+0x50 0.00% 0% 0.2us( 19us) 0us 149 100% 0% 0% task_dumpable+0x20 0% 0.52% 24us( 846us)(0.00%) 290102 99.5% 0.52% 0% task_rq_lock+0xa0 0% 0% 0us 4285 100% 0% 0% test_clear_page_dirty+0x90 0% 0% 0us 301 100% 0% 0% test_clear_page_writeback+0x90 0% 0% 0us 301 100% 0% 0% test_set_page_writeback+0x90 0.00% 0% 7.6us( 12ms) 0us 1992 100% 0% 0% try_to_free_buffers+0x90 0.04% 0.09% 1.1us( 82us) 11us( 79us)(0.00%) 129318 100% 0.09% 0% vma_adjust+0x140 0.00% 0% 0.3us( 47us) 0us 67196 100% 0% 0% vma_adjust+0x2d0 0.10% 0.06% 1.5us( 57ms) 11us( 45us)(0.00%) 255899 100% 0.06% 0% vma_link+0x60 0.00% 0% 0.4us( 62us) 0us 6259 100% 0% 0% vn_hold+0x70 0.00% 0% 0.5us( 19us) 0us 1184 100% 0% 0% vn_purge+0x30 0.00% 0% 0.1us( 4.1us) 0us 1184 100% 0% 0% vn_reclaim+0x100 0.00% 0% 0.1us( 6.1us) 0us 1184 100% 0% 0% vn_rele+0x130 0.00% 0% 0.1us( 5.5us) 0us 1184 100% 0% 0% vn_rele+0x70 0.00% 0% 0.0us( 1.1us) 0us 5046 100% 0% 0% vn_revalidate+0xf0 0.00% 0% 0.1us( 0.1us) 0us 1184 100% 0% 0% vn_wakeup+0x20 0% 0% 0us 29157 100% 0% 0% wait_for_completion+0x1d0 0% 0% 0us 29157 100% 0% 0% wait_for_completion+0x50 0% 0% 0us 30023 100% 0% 0% wait_task_zombie+0x170 0% 0% 0us 95968 100% 0% 0% worker_thread+0x2a0 0% 0% 0us 97005 100% 0% 0% worker_thread+0x430 0.00% 0.72% 1.0us( 12us) 2.7us( 2.7us)(0.00%) 138 99.3% 0.72% 0% xfs_alloc_clear_busy+0x60 0.00% 0% 1.4us( 17us) 0us 139 100% 0% 0% xfs_alloc_mark_busy+0x60 0.00% 0% 0.3us( 5.1us) 0us 145 100% 0% 0% xfs_alloc_search_busy+0x60 0.00% 0% 0.9us( 21us) 0us 144 100% 0% 0% xfs_iextract+0xf0 0.16% 0.01% 73us(2302us) 432us( 432us)(0.00%) 8249 100% 0.01% 0% xfs_iflush+0x3c0 0.00% 0% 3.4us( 64us) 0us 309 100% 0% 0% xfs_iget_core+0x430 0.00% 0% 0.2us( 3.4us) 0us 97 100% 0% 0% xfs_map_blocks+0xf0 - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - RWLOCK READS HOLD MAX RDR BUSY PERIOD WAIT UTIL CON MEAN RDRS MEAN( MAX ) MEAN( MAX )( %CPU) TOTAL NOWAIT SPIN NAME 0.06% 39us(1223us)(0.00%) 904473 100% 0.06% *TOTAL* 0.00% 0% 0.3us 2 0.3us( 44us) 0us 30495 100% 0% binfmt_lock 0% 0us 30206 100% 0% search_binary_handler+0x80 0% 0us 289 100% 0% search_binary_handler+0x420 0.00% 0% 19.4us 1 19us( 186us) 0us 97 100% 0% file_systems_lock 0% 0us 97 100% 0% get_filesystem_list+0x30 0.12% 0.47% 4.2us 2 4.2us( 71ms) 39us(1223us)(0.00%) 114236 99.5% 0.47% tasklist_lock 0.04% 113us(1223us)(0.00%) 36528 100% 0.04% do_sigaction+0x260 0.67% 37us( 165us)(0.00%) 77182 99.3% 0.67% do_wait+0x160 0% 0us 371 100% 0% getrusage+0x40 0% 0us 149 100% 0% proc_pid_lookup+0x80 0% 0us 6 100% 0% session_of_pgrp+0x20 21.1% 0% 238.3us 3 26ms(40450ms) 0us 3152 100% 0% vmlist_lock 0% 0us 3152 100% 0% get_vmalloc_info+0x40 0% 0us 30023 100% 0% copy_process+0x17d0 0% 0us 1341 100% 0% d_path+0x30 0% 0us 18468 100% 0% link_path_walk+0x1e50 0% 0us 24437 100% 0% link_path_walk+0xf80 0% 0us 673103 100% 0% path_lookup+0x60 0% 0us 6595 100% 0% sys_getcwd+0x80 0% 0us 1318 100% 0% xfs_iget_core+0x60 0% 0us 1208 100% 0% xfs_inode_incore+0x60 - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - RWLOCK WRITES HOLD WAIT (ALL) WAIT (WW) UTIL CON MEAN( MAX ) MEAN( MAX )( %CPU) MEAN( MAX ) TOTAL NOWAIT SPIN( WW ) NAME 0.11% 0.0us( 144us) 352us( 37ms)(0.00%) 63us( 636us) 144465 99.9% 0.00%(0.11%) *TOTAL* 0.00% 0% 0.1us( 1.0us) 0us 0us 13 100% 0%( 0%) [0xe000003036799a40] 0.00% 0% 0.1us( 1.0us) 0us 0us 13 100% 0%( 0%) neigh_periodic_timer+0x140 0.00% 0% 14us( 144us) 0us 0us 13 100% 0%( 0%) arp_tbl+0x17c 0.00% 0% 14us( 144us) 0us 0us 13 100% 0%( 0%) neigh_periodic_timer+0x40 0% 0.02% 18us( 12us)(0.00%) 8.9us( 12us) 10230 100% 0%(0.02%) fasync_lock 0% 0.02% 18us( 12us)(0.00%) 8.9us( 12us) 10230 100% 0%(0.02%) fasync_helper+0x80 0.00% 0% 56us( 56us) 0us 0us 1 100% 0%( 0%) ipfrag_lock 0.00% 0% 56us( 56us) 0us 0us 1 100% 0%( 0%) ipfrag_secret_rebuild+0x40 0% 0.18% 356us( 37ms)(0.00%) 64us( 636us) 90073 99.8% 0.01%(0.17%) tasklist_lock 0% 0.02% 6260us( 37ms)(0.00%) 42us( 132us) 30023 100% 0.00%(0.02%) copy_process+0xd40 0% 0.50% 128us( 636us)(0.00%) 66us( 636us) 30023 99.5% 0.01%(0.49%) exit_notify+0xd0 0% 0.01% 43us( 32us)(0.00%) 22us( 32us) 30023 100% 0%(0.01%) release_task+0xb0 0% 0% 0us 0us 4 100% 0%( 0%) sys_setpgid+0x90 0.00% 0% 0.1us( 24us) 0us 0us 43567 100% 0%( 0%) set_fs_pwd+0x20 0.00% 0% 1.4us( 37us) 0us 0us 144 100% 0%( 0%) xfs_finish_reclaim+0x30 0.00% 0% 0.1us( 0.2us) 0us 0us 144 100% 0%( 0%) xfs_iextract+0x30 0.00% 0% 0.3us( 7.6us) 0us 0us 280 100% 0%( 0%) xfs_iget_core+0x230 _________________________________________________________________________________________________________________________ Number of read locks found=4 [-- Attachment #3: lockstat-2.6.9-rc2-rcu.txt --] [-- Type: text/plain, Size: 41879 bytes --] ___________________________________________________________________________________________ System: Linux ascender 2.6.9-rc2 #2 SMP Tue Sep 14 11:08:32 CDT 2004 ia64 Total counts All (512) CPUs Start time: Tue Sep 14 12:18:56 2004 End time: Tue Sep 14 12:24:11 2004 Delta Time: 274.27 sec. Hash table slots in use: 347. Global read lock slots in use: 771. - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - SPINLOCKS HOLD WAIT UTIL CON MEAN( MAX ) MEAN( MAX )(% CPU) TOTAL NOWAIT SPIN RJECT NAME 0.07% 3.2us( 14ms) 2392us( 13ms)(0.29%) 240153544 100% 0.07% 0.00% *TOTAL* 0.00% 0% 0.2us( 2.0us) 0us 15 100% 0% 0% [0xe000003060e71e40] 0.00% 0% 0.2us( 2.0us) 0us 15 100% 0% 0% unmap_mapping_range+0xc0 0.00% 0.00% 0.2us( 23us) 0.9us( 0.9us)(0.00%) 47023 100% 0.00% 0% [0xe00000b003746cd0] 0.00% 0% 0.2us( 0.2us) 0us 1 100% 0% 0% xfs_log_move_tail+0x310 0.00% 0% 0.5us( 23us) 0us 79 100% 0% 0% xfs_log_need_covered+0x100 0.00% 0% 0.1us( 3.8us) 0us 5080 100% 0% 0% xfs_log_notify+0x40 0.00% 0% 4.2us( 11us) 0us 240 100% 0% 0% xlog_state_do_callback+0x40 0.00% 0% 0.0us( 0.1us) 0us 240 100% 0% 0% xlog_state_do_callback+0x210 0.00% 0.42% 2.7us( 13us) 0.9us( 0.9us)(0.00%) 240 99.6% 0.42% 0% xlog_state_do_callback+0x300 0.00% 0% 0.2us( 0.2us) 0us 241 100% 0% 0% xlog_state_done_syncing+0x40 0.00% 0% 0.3us( 12us) 0us 10307 100% 0% 0% xlog_state_get_iclog_space+0x30 0.00% 0% 0.1us( 3.5us) 0us 4804 100% 0% 0% xlog_state_put_ticket+0x20 0.00% 0% 0.1us( 4.4us) 0us 10400 100% 0% 0% xlog_state_release_iclog+0x50 0.00% 0% 1.2us( 5.6us) 0us 128 100% 0% 0% xlog_state_sync_all+0x30 0.00% 0% 0.1us( 2.4us) 0us 55 100% 0% 0% xlog_state_sync_all+0x440 0.00% 0% 3.3us( 15us) 0us 46 100% 0% 0% xlog_state_sync+0x40 0.00% 0% 1.1us( 5.5us) 0us 38 100% 0% 0% xlog_state_sync+0x3f0 0.00% 0% 0.1us( 0.1us) 0us 15 100% 0% 0% xlog_state_want_sync+0x20 0.00% 0% 0.4us( 18us) 0us 4804 100% 0% 0% xlog_ticket_get+0x50 0.00% 0% 0.1us( 0.1us) 0us 10160 100% 0% 0% xlog_write+0x5f0 0.00% 0% 0.1us( 0.5us) 0us 15 100% 0% 0% xlog_write+0x6c0 0.00% 0% 0.1us( 0.1us) 0us 130 100% 0% 0% xlog_write+0x800 0.00% 0% 0.1us( 25us) 0us 34870 100% 0% 0% [0xe00000b003746d70] 0.00% 0% 0.1us( 10us) 0us 5952 100% 0% 0% xfs_log_move_tail+0x70 0.00% 0% 0.0us( 12us) 0us 10400 100% 0% 0% xlog_assign_tail_lsn+0x50 0.00% 0% 0.4us( 25us) 0us 4804 100% 0% 0% xlog_grant_log_space+0x40 0.00% 0% 0.1us( 5.6us) 0us 6680 100% 0% 0% xlog_grant_push_ail+0x50 0.00% 0% 0.1us( 0.4us) 0us 1876 100% 0% 0% xlog_regrant_reserve_log_space+0x50 0.00% 0% 1.1us( 3.8us) 0us 114 100% 0% 0% xlog_regrant_write_log_space+0x90 0.00% 0% 0.1us( 0.6us) 0us 240 100% 0% 0% xlog_state_do_callback+0x1c0 0.00% 0% 0.1us( 4.4us) 0us 4804 100% 0% 0% xlog_ungrant_log_space+0x50 0% 0% 0us 26867 100% 0% 0% [0xe00005b00387a080] 0% 0% 0us 26867 100% 0% 0% sn_dma_flush+0x1e0 0.00% 0.01% 0.1us( 4.6us) 2.4us( 2.6us)(0.00%) 32086 100% 0.01% 0% [0xe0000c3003ea3024] 0.00% 0% 0.2us( 1.5us) 0us 435 100% 0% 0% xfs_buf_iodone+0x30 0.00% 0% 0.1us( 2.7us) 0us 48 100% 0% 0% xfs_buf_item_unpin+0x160 0.00% 0% 0.0us( 0.1us) 0us 161 100% 0% 0% xfs_efi_item_unpin+0x30 0.00% 0% 0.1us( 1.2us) 0us 161 100% 0% 0% xfs_efi_release+0x30 0.00% 0% 0.1us( 1.4us) 0us 595 100% 0% 0% xfs_iflush_done+0xc0 0.00% 0% 0.1us( 4.6us) 0us 605 100% 0% 0% xfs_iflush_int+0x430 0.00% 0% 0.1us( 2.1us) 0us 19681 100% 0% 0% xfs_trans_chunk_committed+0x210 0.00% 0.03% 0.1us( 3.9us) 2.4us( 2.6us)(0.00%) 10400 100% 0.03% 0% xfs_trans_tail_ail+0x20 0.00% 0% 0.2us( 11us) 0us 14069 100% 0% 0% [0xe0000c3003ea3110] 0.00% 0% 0.2us( 11us) 0us 10123 100% 0% 0% xfs_mod_incore_sb+0x20 0.00% 0% 0.1us( 3.9us) 0us 3946 100% 0% 0% xfs_mod_incore_sb_batch+0x30 0% 0% 0us 26866 100% 0% 0% [0xe0000cb07b91a018] 0% 0% 0us 26866 100% 0% 0% scsi_put_command+0xe0 0.16% 0.04% 3.2us( 632us) 5.6us( 31us)(0.00%) 134334 100% 0.04% 0% [0xe0000cb07b91a040] 0.15% 0.01% 15us( 632us) 5.9us( 7.0us)(0.00%) 26867 100% 0.01% 0% qla1280_intr_handler+0x30 0.01% 0.04% 0.9us( 25us) 2.0us( 2.7us)(0.00%) 26867 100% 0.04% 0% scsi_device_unbusy+0x50 0% 0.04% 2.6us( 3.4us)(0.00%) 26867 100% 0.04% 0% scsi_dispatch_cmd+0x340 0% 0.09% 8.9us( 31us)(0.00%) 26867 100% 0.09% 0% scsi_request_fn+0x2d0 0% 0% 0us 26866 100% 0% 0% scsi_run_queue+0xa0 0.05% 0.14% 0.3us( 76us) 6.1us( 68us)(0.00%) 426645 99.9% 0.14% 0% [0xe00011307be47034] 0% 0.13% 5.4us( 22us)(0.00%) 26015 99.9% 0.13% 0% __cfq_get_queue+0x1f0 0% 0.27% 6.7us( 68us)(0.00%) 55197 99.7% 0.27% 0% __make_request+0x150 0.00% 0% 3.8us( 3.8us) 0us 1 100% 0% 0% blk_insert_request+0x80 0.00% 0.04% 0.0us( 69us) 5.6us( 16us)(0.00%) 26866 100% 0.04% 0% blk_run_queue+0x40 0% 0.17% 6.7us( 30us)(0.00%) 52881 99.8% 0.17% 0% cfq_get_queue+0x50 0.05% 0.14% 2.7us( 76us) 7.1us( 30us)(0.00%) 53331 99.9% 0.14% 0% generic_unplug_device+0x40 0% 0.17% 4.7us( 18us)(0.00%) 52881 99.8% 0.17% 0% get_request+0x80 0% 0.12% 7.9us( 56us)(0.00%) 26015 99.9% 0.12% 0% get_request+0x4d0 0% 0.02% 2.6us( 5.0us)(0.00%) 26867 100% 0.02% 0% scsi_device_unbusy+0xb0 0% 0.02% 7.3us( 19us)(0.00%) 26866 100% 0.02% 0% scsi_end_request+0x160 0.00% 0.36% 0.0us( 49us) 5.2us( 19us)(0.00%) 26867 99.6% 0.36% 0% scsi_request_fn+0x520 0% 0.03% 4.7us( 8.7us)(0.00%) 52858 100% 0.03% 0% scsi_request_fn+0x5b0 0.00% 0% 0.0us( 0.8us) 0us 53732 100% 0% 0% [0xe00011307be47038] 0% 0% 0us 26866 100% 0% 0% scsi_get_command+0x110 0.00% 0% 0.1us( 0.8us) 0us 26866 100% 0% 0% scsi_put_command+0x70 0.00% 0% 0.2us( 6.1us) 0us 63 100% 0% 0% [0xe0001330032bb504] 0.00% 0% 0.2us( 6.1us) 0us 63 100% 0% 0% do_select+0x60 0% 0% 0us 192 100% 0% 0% [0xe00040b003d38380] 0% 0% 0us 130 100% 0% 0% qla2x00_intr_handler+0x70 0% 0% 0us 62 100% 0% 0% qla2x00_mailbox_command+0xe0 0% 0% 0us 134 100% 0% 0% [0xe00040b003d3a480] 0% 0% 0us 130 100% 0% 0% qla2x00_next+0x80 0% 0% 0us 2 100% 0% 0% qla2x00_restart_queues+0x120 0% 0% 0us 2 100% 0% 0% qla2x00_restart_queues+0x390 0% 0% 0us 186 100% 0% 0% [0xe00040b003d3c478] 0% 0% 0us 62 100% 0% 0% qla2x00_intr_handler+0x4e0 0% 0% 0us 62 100% 0% 0% qla2x00_mailbox_command+0x9c0 0% 0% 0us 62 100% 0% 0% qla2x00_mailbox_command+0xba0 0% 0% 0us 8 100% 0% 0% [0xe00055b07bd2fe18] 0% 0% 0us 4 100% 0% 0% __down_interruptible+0xc0 0% 0% 0us 4 100% 0% 0% __down_interruptible+0x240 0.00% 0% 6.8us( 22us) 0us 12 100% 0% 0% [0xe00058b07808924c] 0.00% 0% 0.4us( 1.6us) 0us 6 100% 0% 0% rwsem_down_read_failed+0x60 0.00% 0% 13us( 22us) 0us 6 100% 0% 0% rwsem_wake+0x30 0% 0% 0us 1 100% 0% 0% [0xe00062300376510c] 0% 0% 0us 1 100% 0% 0% pcibr_try_set_device+0x50 0% 0% 0us 7 100% 0% 0% batch_lock 0% 0% 0us 7 100% 0% 0% batch_entropy_store+0x80 0.01% 0.03% 6.6us( 85us) 5.7us( 5.7us)(0.00%) 3155 100% 0.03% 0% bdev_lock 0.01% 0.03% 6.6us( 85us) 5.7us( 5.7us)(0.00%) 3155 100% 0.03% 0% nr_blockdev_pages+0x20 0.00% 0% 0.2us( 39us) 0us 19868 100% 0% 0% cdev_lock 0.00% 0% 0.2us( 39us) 0us 19868 100% 0% 0% chrdev_open+0x40 0.00% 0% 1.6us( 5.0us) 0us 512 100% 0% 0% cpe_history_lock.4 0.00% 0% 1.6us( 5.0us) 0us 512 100% 0% 0% ia64_mca_cpe_int_handler+0xa0 0.10% 0.03% 0.1us( 52us) 3.1us( 993us)(0.00%) 2701927 100% 0.03% 0% dcache_lock 0.00% 0.02% 0.1us( 19us) 1.9us( 3.4us)(0.00%) 27727 100% 0.02% 0% d_alloc+0x260 0.00% 0% 0.3us( 4.0us) 0us 1207 100% 0% 0% d_delete+0x40 0.00% 0.02% 0.1us( 11us) 2.2us( 3.7us)(0.00%) 27890 100% 0.02% 0% d_instantiate+0x50 0.00% 0% 3.5us( 12us) 0us 97 100% 0% 0% d_move+0x60 0.00% 0.19% 1.9us( 11us) 1.0us( 1.2us)(0.00%) 1043 99.8% 0.19% 0% d_path+0x110 0.00% 0.04% 0.3us( 31us) 1.7us( 4.4us)(0.00%) 27726 100% 0.04% 0% d_rehash+0xc0 0.00% 0% 0.1us( 0.1us) 0us 1043 100% 0% 0% d_splice_alias+0xc0 0.09% 0.04% 0.1us( 52us) 3.1us( 993us)(0.00%) 2564651 100% 0.04% 0% dput+0x50 0.00% 0% 0.1us( 1.9us) 0us 24437 100% 0% 0% link_path_walk+0x1000 0.00% 0% 0.1us( 2.3us) 0us 18468 100% 0% 0% link_path_walk+0x1ed0 0.00% 0% 0.8us( 4.4us) 0us 149 100% 0% 0% proc_pid_unhash+0x50 0.00% 0% 1.0us( 11us) 0us 298 100% 0% 0% prune_dcache+0x50 0.00% 0% 0.1us( 4.1us) 0us 149 100% 0% 0% prune_dcache+0x380 0.00% 0% 0.2us( 11us) 0us 447 100% 0% 0% select_parent+0x30 0.00% 0% 0.8us( 23us) 0us 6595 100% 0% 0% sys_getcwd+0x210 0.02% 0.01% 0.1us( 23us) 1.6us( 11us)(0.00%) 516145 100% 0.01% 0% files_lock 0.00% 0.04% 0.1us( 0.5us) 2.6us( 2.6us)(0.00%) 2818 100% 0.04% 0% check_tty_count+0x20 0.01% 0.02% 0.1us( 15us) 1.3us( 3.9us)(0.00%) 255959 100% 0.02% 0% file_kill+0x70 0.01% 0.01% 0.1us( 23us) 2.0us( 11us)(0.00%) 257368 100% 0.01% 0% file_move+0x40 0% 0% 0us 756 100% 0% 0% filp_count_lock 0% 0% 0us 441 100% 0% 0% filp_ctor+0x70 0% 0% 0us 315 100% 0% 0% filp_dtor+0x40 0% 0.00% 3.1us( 3.1us)(0.00%) 89822 100% 0.00% 0% ia64_ctx 0% 0.00% 3.1us( 3.1us)(0.00%) 29924 100% 0.00% 0% exec_mmap+0x4f0 0% 0% 0us 20994 100% 0% 0% schedule+0xde0 0% 0% 0us 38904 100% 0% 0% smp_flush_tlb_mm+0x310 0% 0% 0us 512 100% 0% 0% ia64_state_log+0x60 0% 0% 0us 512 100% 0% 0% ia64_log_get+0x80 0.00% 0% 0.1us( 0.2us) 0us 2 100% 0% 0% inet_peer_unused_lock 0.00% 0% 0.1us( 0.2us) 0us 2 100% 0% 0% cleanup_once+0x60 0.04% 0.06% 0.3us( 43us) 5.0us( 31us)(0.00%) 353580 100% 0.06% 0% inode_lock 0.00% 0.01% 0.2us( 13us) 1.8us( 2.2us)(0.00%) 47928 100% 0.01% 0% __mark_inode_dirty+0xf0 0.01% 0.13% 0.4us( 43us) 7.3us( 31us)(0.00%) 75399 99.9% 0.13% 0% __sync_single_inode+0x100 0.00% 0% 0.1us( 10us) 0us 4746 100% 0% 0% generic_delete_inode+0x1f0 0.00% 0.01% 0.1us( 23us) 2.0us( 2.2us)(0.00%) 22314 100% 0.01% 0% get_new_inode_fast+0x50 0.00% 0.00% 0.3us( 23us) 2.5us( 2.5us)(0.00%) 22314 100% 0.00% 0% iget_locked+0xb0 0.00% 0% 0.2us( 12us) 0us 6326 100% 0% 0% igrab+0x20 0.00% 0.06% 0.1us( 40us) 2.7us( 7.6us)(0.00%) 92603 100% 0.06% 0% iput+0xa0 0.00% 0.04% 0.3us( 18us) 2.1us( 2.4us)(0.00%) 4712 100% 0.04% 0% new_inode+0x70 0.00% 0.13% 0.2us( 5.9us) 5.1us( 5.1us)(0.00%) 765 99.9% 0.13% 0% sync_inodes_sb+0x140 0.02% 0.08% 0.6us( 37us) 3.6us( 13us)(0.00%) 75910 100% 0.08% 0% sync_sb_inodes+0x630 0.00% 0.18% 1.9us( 25us) 2.1us( 2.1us)(0.00%) 563 99.8% 0.18% 0% writeback_inodes+0x20 0.03% 0.01% 2.2us( 791us) 8.9us( 16us)(0.00%) 37374 100% 0.01% 0% kernel_flag 0.01% 0% 1.0us( 217us) 0us 19868 100% 0% 0% chrdev_open+0x1e0 0.00% 0.03% 0.2us( 17us) 1.8us( 1.8us)(0.00%) 3241 100% 0.03% 0% de_put+0x50 0.00% 0% 0.1us( 0.1us) 0us 696 100% 0% 0% linvfs_ioctl+0x140 0.02% 0% 13us( 791us) 0us 3391 100% 0% 0% proc_lookup+0x60 0.00% 0.05% 1.1us( 67us) 16us( 16us)(0.00%) 2123 100% 0.05% 0% sys_ioctl+0xa0 0.00% 0% 0.9us( 24us) 0us 6592 100% 0% 0% sys_sysctl+0xd0 0.00% 0% 4.5us( 164us) 0us 1409 100% 0% 0% tty_release+0x50 0.00% 0% 73us( 477us) 0us 54 100% 0% 0% tty_write+0x440 0% 0% 0us 12 100% 0% 0% logbuf_lock 0% 0% 0us 8 100% 0% 0% release_console_sem+0x50 0% 0% 0us 4 100% 0% 0% vprintk+0x60 0.01% 0.10% 0.3us( 26us) 2.0us( 17us)(0.00%) 110873 99.9% 0.10% 0% mmlist_lock 0.00% 0.04% 0.1us( 3.3us) 3.3us( 17us)(0.00%) 20994 100% 0.04% 0% copy_mm+0x2a0 0.01% 0.03% 0.8us( 26us) 1.2us( 2.8us)(0.00%) 29924 100% 0.03% 0% exec_mmap+0x40 0.00% 0.16% 0.2us( 16us) 2.0us( 14us)(0.00%) 59955 99.8% 0.16% 0% mmput+0x30 0% 0% 0us 1052 100% 0% 0% page_uptodate_lock.1 0% 0% 0us 1052 100% 0% 0% end_buffer_async_write+0xc0 0.00% 0.01% 0.2us( 20us) 0.2us( 0.2us)(0.00%) 9033 100% 0.01% 0% pbd_delwrite_lock 0.00% 0% 2.8us( 20us) 0us 314 100% 0% 0% pagebuf_daemon+0x200 0.00% 0.01% 0.1us( 3.8us) 0.2us( 0.2us)(0.00%) 8232 100% 0.01% 0% pagebuf_delwri_dequeue+0x30 0.00% 0% 0.4us( 3.4us) 0us 487 100% 0% 0% pagebuf_delwri_queue+0x30 0% 0% 0us 234 100% 0% 0% pdflush_lock 0% 0% 0us 78 100% 0% 0% __pdflush+0x220 0% 0% 0us 78 100% 0% 0% __pdflush+0x320 0% 0% 0us 78 100% 0% 0% pdflush_operation+0x60 0.85% 8.8% 1.3us(3489us) 2617us( 13ms)(0.29%) 1766106 91.2% 8.8% 0% rcu_state 0.01% 0.83% 4.7us( 369us) 828us(5897us)(0.00%) 6874 99.2% 0.83% 0% __rcu_process_callbacks+0x260 0.83% 8.8% 1.3us(3489us) 2617us( 13ms)(0.29%) 1759232 91.2% 8.8% 0% cpu_quiet+0x2c0 0.00% 0% 0.5us( 7.1us) 0us 54 100% 0% 0% redirect_lock 0.00% 0% 0.5us( 7.1us) 0us 54 100% 0% 0% redirected_tty_write+0x30 0.00% 0% 2.3us( 11us) 0us 97 100% 0% 0% rename_lock+0x4 0.00% 0% 2.3us( 11us) 0us 97 100% 0% 0% d_move+0x80 0% 0.64% 22us( 26us)(0.00%) 627 99.4% 0.64% 0% sal_console_port+0x40 0% 0% 0us 4 100% 0% 0% sn_sal_console_write+0x380 0% 1.3% 22us( 26us)(0.00%) 299 98.7% 1.3% 0% sn_sal_interrupt+0x200 0% 0% 0us 108 100% 0% 0% uart_put_char+0xa0 0% 0% 0us 162 100% 0% 0% uart_start+0x50 0% 0% 0us 54 100% 0% 0% uart_write+0x400 0.00% 0% 0.5us( 29us) 0us 3069 100% 0% 0% sb_lock 0.00% 0% 0.4us( 6.7us) 0us 810 100% 0% 0% get_super_to_sync+0x30 0.00% 0% 1.4us( 4.8us) 0us 15 100% 0% 0% get_super_to_sync+0x30 0.00% 0% 0.1us( 1.1us) 0us 850 100% 0% 0% put_super+0x20 0.00% 0% 1.2us( 6.4us) 0us 45 100% 0% 0% set_sb_syncing+0x20 0.00% 0% 1.7us( 11us) 0us 30 100% 0% 0% sync_filesystems+0x70 0.00% 0% 1.4us( 27us) 0us 60 100% 0% 0% sync_filesystems+0x170 0.00% 0% 1.6us( 5.4us) 0us 133 100% 0% 0% sync_supers+0x30 0.00% 0% 0.4us( 7.1us) 0us 563 100% 0% 0% writeback_inodes+0x40 0.00% 0% 1.0us( 29us) 0us 563 100% 0% 0% writeback_inodes+0x210 0.00% 0% 0.2us( 18us) 0us 3155 100% 0% 0% swaplock 0.00% 0% 0.2us( 18us) 0us 3155 100% 0% 0% si_swapinfo+0x20 0.00% 0% 0.1us( 3.6us) 0us 30031 100% 0% 0% uidhash_lock 0.00% 0% 0.1us( 3.6us) 0us 30031 100% 0% 0% free_uid+0x30 0.00% 0.02% 0.8us( 13us) 3.1us( 3.1us)(0.00%) 4298 100% 0.02% 0% vfsmount_lock 0.00% 0% 0.1us( 3.6us) 0us 894 100% 0% 0% __d_path+0x2b0 0.00% 0.03% 1.1us( 13us) 3.1us( 3.1us)(0.00%) 3404 100% 0.03% 0% lookup_mnt+0x80 0.00% 0% 0.1us( 11us) 0us 19073 100% 0% 0% vnumber_lock 0.00% 0% 0.1us( 11us) 0us 19073 100% 0% 0% vn_initialize+0xd0 0.93% 0% 7.9us(1132us) 0us 322268 100% 0% 0% xtime_lock+0x4 0.93% 0% 7.9us(1132us) 0us 322268 100% 0% 0% timer_interrupt+0x330 0.07% 0.00% 0.1us( 25us) 3.1us( 11us)(0.00%) 1686850 100% 0.00% 0% __d_lookup+0x190 0% 0.28% 3.2us( 4.8us)(0.00%) 1450 99.7% 0.28% 0% __down+0x200 0% 0.27% 2.1us( 2.7us)(0.00%) 1498 99.7% 0.27% 0% __down+0xc0 0% 0% 0us 2761 100% 0% 0% __down_trylock+0x40 0.00% 0% 0.1us( 23us) 0us 30031 100% 0% 0% __exit_signal+0x80 0.01% 0% 0.1us( 4.5us) 0us 152486 100% 0% 0% __mod_timer+0x120 0% 0% 0us 152486 100% 0% 0% __mod_timer+0xa0 0% 0.03% 1.5us( 12us)(0.00%) 1157082 100% 0.03% 0% __page_cache_release+0x70 0% 0% 0us 19600 100% 0% 0% __pagevec_lru_add+0xe0 0% 0.03% 8.2us( 21us)(0.00%) 193047 100% 0.03% 0% __pagevec_lru_add_active+0xe0 0.01% 0% 0.1us( 17us) 0us 203672 100% 0% 0% __pmd_alloc+0x60 0% 0% 0us 80491 100% 0% 0% __queue_work+0x30 0% 0% 0us 2050 100% 0% 0% __set_page_dirty_nobuffers+0xd0 0% 0.02% 3.6us( 9.7us)(0.00%) 213353 100% 0.02% 0% __wake_up+0x30 0% 0% 0us 30031 100% 0% 0% __wake_up_sync+0x50 0.01% 0% 0.4us( 37us) 0us 84165 100% 0% 0% _pagebuf_find+0xd0 0% 0% 0us 3631 100% 0% 0% activate_page+0x70 0% 0% 0us 27427 100% 0% 0% add_to_page_cache+0x80 0% 0% 0us 130349 100% 0% 0% add_wait_queue+0x50 0% 0% 0us 46 100% 0% 0% add_wait_queue_exclusive+0x50 0.01% 0.00% 0.1us( 12us) 1.3us( 1.9us)(0.00%) 264157 100% 0.00% 0% anon_vma_link+0x30 0.02% 0% 0.2us( 38us) 0us 281171 100% 0% 0% anon_vma_prepare+0xc0 0.01% 0.00% 0.1us( 41us) 6.5us( 32us)(0.00%) 562479 100% 0.00% 0% anon_vma_unlink+0x30 0% 0.01% 2.2us( 2.3us)(0.00%) 30031 100% 0.01% 0% buffered_rmqueue+0x3f0 0.02% 0% 2.2us( 55us) 0us 18846 100% 0% 0% cache_alloc_refill+0xb0 0.01% 0% 2.0us( 36us) 0us 7284 100% 0% 0% cache_flusharray+0x30 0.00% 0% 0.1us( 0.2us) 0us 2461 100% 0% 0% cache_grow+0x260 0.00% 0% 0.5us( 11us) 0us 2461 100% 0% 0% cache_grow+0xf0 0% 0.00% 5.7us( 29us)(0.00%) 8444352 100% 0.00% 0% cache_reap+0x230 0% 0% 0us 354 100% 0% 0% cache_reap+0x430 0.01% 0% 0.5us( 23us) 0us 42332 100% 0% 0% change_protection+0x90 0% 0% 0us 29462 100% 0% 0% complete+0x40 0.00% 0% 0.4us( 26us) 0us 29924 100% 0% 0% compute_creds+0x20 0.01% 0% 1.0us( 82us) 0us 30031 100% 0% 0% copy_files+0x1c0 0.00% 0% 0.1us( 10us) 0us 17410 100% 0% 0% copy_files+0x200 0.05% 0% 7.3us( 33us) 0us 17410 100% 0% 0% copy_files+0x2c0 0.01% 0.01% 0.1us( 14us) 4.2us( 9.1us)(0.00%) 363042 100% 0.01% 0% copy_mm+0x5a0 0.86% 0% 4.7us(2058us) 0us 506636 100% 0% 0% copy_mm+0x5e0 1.2% 0% 6.6us(2058us) 0us 485642 100% 0% 0% copy_page_range+0x2a0 155% 0.13% 121us( 13ms) 9.0us(1585us)(0.00%) 3518464 99.9% 0.13% 0% cpu_quiet+0x60 0.00% 0% 0.3us( 3.8us) 0us 2050 100% 0% 0% create_empty_buffers+0xa0 0.00% 0% 0.1us( 0.1us) 0us 1207 100% 0% 0% d_delete+0x50 0.00% 0% 1.5us( 2.4us) 0us 97 100% 0% 0% d_move+0x100 0.00% 0% 1.9us( 2.7us) 0us 49 100% 0% 0% d_move+0x560 0.00% 0% 1.8us( 3.6us) 0us 48 100% 0% 0% d_move+0xe0 0.00% 0% 0.1us( 11us) 0us 27726 100% 0% 0% d_rehash+0xd0 0% 0.00% 1.0us( 1.0us)(0.00%) 79353 100% 0.00% 0% del_timer+0x80 0.01% 0.00% 0.1us( 27us) 2.8us( 3.0us)(0.00%) 179833 100% 0.00% 0% deny_write_access+0x40 0.00% 0% 0.1us( 9.7us) 0us 46847 100% 0% 0% dnotify_flush+0xa0 0.03% 0.00% 0.2us( 212us) 4.1us( 16us)(0.00%) 330705 100% 0.00% 0% dnotify_parent+0x60 0.01% 0% 0.6us( 24us) 0us 27234 100% 0% 0% do_IRQ+0x1d0 0.00% 0% 0.4us( 8.5us) 0us 27234 100% 0% 0% do_IRQ+0x2b0 0.04% 0% 0.3us( 183us) 0us 384104 100% 0% 0% do_anonymous_page+0x270 0.00% 0% 0.1us( 6.0us) 0us 30031 100% 0% 0% do_exit+0x3d0 0.00% 0% 0.0us( 12us) 0us 30031 100% 0% 0% do_exit+0x460 0.00% 0% 0.0us( 9.7us) 0us 30031 100% 0% 0% do_exit+0x4b0 0.00% 0% 0.0us( 6.6us) 0us 30031 100% 0% 0% do_exit+0x6d0 0.00% 0% 0.1us( 2.5us) 0us 933 100% 0% 0% do_fcntl+0xb0 0.12% 0% 2.2us( 13ms) 0us 153104 100% 0% 0% do_munmap+0x220 0.19% 0% 0.2us( 236us) 0us 2400489 100% 0% 0% do_no_page+0x220 0% 0% 0us 30031 100% 0% 0% do_notify_parent+0x2e0 0% 0.06% 3.5us( 12us)(0.00%) 158844 100% 0.06% 0% do_page_cache_readahead+0x140 0% 0% 0us 24872 100% 0% 0% do_page_cache_readahead+0x270 0% 0% 0us 283362 100% 0% 0% do_sigaction+0x110 0% 0% 0us 36542 100% 0% 0% do_sigaction+0x2a0 0.11% 0% 0.6us( 537us) 0us 486122 100% 0% 0% do_wp_page+0x2d0 0.00% 1.9% 0.7us( 226us) 0us 14714 98.1% 0% 1.9% double_lock_balance+0x20 0.00% 82.3% 12us( 137us) 212us(1619us)(0.00%) 96 17.7% 82.3% 0% double_lock_balance+0x80 0.00% 59.3% 2.9us( 87us) 27us( 562us)(0.00%) 285 40.7% 59.3% 0% double_lock_balance+0xa0 0.00% 0% 1.0us( 639us) 0us 11554 100% 0% 0% double_rq_lock+0x40 0.00% 0.15% 0.1us( 3.1us) 237us( 639us)(0.00%) 20425 99.9% 0.15% 0% double_rq_lock+0x60 0.00% 0.32% 0.3us( 17us) 327us( 584us)(0.00%) 8871 99.7% 0.32% 0% double_rq_lock+0x90 0.02% 0.00% 0.1us( 52us) 4.3us( 6.8us)(0.00%) 417229 100% 0.00% 0% dput+0xb0 0.00% 0% 0.3us( 9.2us) 0us 371 100% 0% 0% dupfd+0x30 0.01% 0% 1.1us(6130us) 0us 29924 100% 0% 0% exec_mmap+0x110 7.3% 0% 392us( 14ms) 0us 50918 100% 0% 0% exit_mmap+0x50 0.00% 0% 0.1us( 13us) 0us 17662 100% 0% 0% expand_fd_array+0x130 0.00% 0% 0.3us( 2.0us) 0us 252 100% 0% 0% expand_fd_array+0x240 0.00% 0% 0.5us( 5.3us) 0us 928 100% 0% 0% expand_stack+0x60 0.00% 0% 0.1us( 13us) 0us 234945 100% 0% 0% fd_install+0x30 0.02% 0% 0.1us( 23us) 0us 438595 100% 0% 0% fget+0x30 0% 0.07% 3.4us( 30us)(0.00%) 2674425 100% 0.07% 0% find_get_page+0x40 0% 0% 0us 4238 100% 0% 0% find_get_pages+0x40 0% 0% 0us 120515 100% 0% 0% find_get_pages_tag+0x40 0% 0.01% 1.1us( 1.9us)(0.00%) 84291 100% 0.01% 0% find_lock_page+0x40 0% 0% 0us 204 100% 0% 0% find_trylock_page+0x40 0% 0.02% 2.3us( 4.2us)(0.00%) 26066 100% 0.02% 0% finish_wait+0x90 0.00% 0% 0.1us( 20us) 0us 38666 100% 0% 0% flush_old_exec+0x4f0 0% 0.08% 3.8us( 16us)(0.00%) 80172 100% 0.08% 0% force_page_cache_readahead+0x170 0% 0% 0us 72 100% 0% 0% force_page_cache_readahead+0x2a0 0% 0.02% 4.7us( 31us)(0.00%) 265111 100% 0.02% 0% free_pages_bulk+0x90 0% 0.10% 4.1us( 18us)(0.00%) 27886 99.9% 0.10% 0% get_signal_to_deliver+0x60 0.02% 0% 0.2us( 28us) 0us 281891 100% 0% 0% get_unused_fd+0x40 0.00% 0% 0.1us( 12us) 0us 21477 100% 0% 0% get_write_access+0x30 0.25% 0% 0.2us( 703us) 0us 3589052 100% 0% 0% handle_mm_fault+0x160 0% 0% 0us 27886 100% 0% 0% handle_signal+0x100 0% 0% 0us 27886 100% 0% 0% ia64_rt_sigreturn+0x1b0 0.00% 0% 0.2us( 12us) 0us 29924 100% 0% 0% install_arg_page+0xc0 0% 0% 0us 30046 100% 0% 0% k_getrusage+0x530 0% 0% 0us 356 100% 0% 0% k_getrusage+0xd0 0.00% 0% 0.1us( 0.9us) 0us 696 100% 0% 0% linvfs_ioctl+0xe0 0.00% 3.1% 1.1us( 56us) 460us( 979us)(0.00%) 228 96.9% 3.1% 0% load_balance+0x170 115% 0.00% 9.4us(1773us) 3.0us( 9.6us)(0.00%) 33485489 100% 0.00% 0% load_balance+0x30 0% 0% 0us 75399 100% 0% 0% mapping_tagged+0x40 0.00% 0.01% 0.1us( 586us) 76us( 207us)(0.00%) 40912 100% 0.01% 0% migration_thread+0x130 0.00% 0% 0.5us( 2.4us) 0us 149 100% 0% 0% mounts_open+0xa0 0.00% 0% 0.1us( 11us) 0us 97133 100% 0% 0% pagebuf_rele+0x60 0.00% 0% 0.1us( 0.1us) 0us 149 100% 0% 0% pid_base_iput+0x30 0% 0% 0us 5044 100% 0% 0% prepare_to_wait+0x60 0% 0.00% 0.2us( 0.3us)(0.00%) 43556 100% 0.00% 0% prepare_to_wait_exclusive+0x60 0.00% 0% 0.0us( 0.2us) 0us 149 100% 0% 0% proc_pid_lookup+0x1e0 0.00% 0% 0.4us( 3.5us) 0us 298 100% 0% 0% prune_dcache+0x130 0.38% 0% 4.0us( 446us) 0us 254607 100% 0% 0% pte_alloc_map+0x140 0.00% 0% 0.1us( 3.3us) 0us 47317 100% 0% 0% put_unused_fd+0x30 0% 0% 0us 5355 100% 0% 0% qla2x00_timer+0x2c0 0% 0.06% 14us( 19us)(0.00%) 19499 100% 0.06% 0% release_pages+0x180 0.07% 0% 6.3us( 252us) 0us 30031 100% 0% 0% release_task+0x60 0% 0% 0us 1993 100% 0% 0% remove_from_page_cache+0x70 0.06% 0.03% 0.2us( 44us) 4.6us( 26us)(0.00%) 748374 100% 0.03% 0% remove_vm_struct+0x50 0% 0.00% 3.5us( 3.5us)(0.00%) 130395 100% 0.00% 0% remove_wait_queue+0x30 0% 0.03% 2.1us( 5.4us)(0.00%) 247968 100% 0.03% 0% rmqueue_bulk+0x40 0.00% 0% 0.6us( 1.4us) 0us 5 100% 0% 0% rt_check_expire+0xe0 0% 0% 0us 73133 100% 0% 0% run_timer_softirq+0x2c0 0% 0.00% 1.0us( 2.0us)(0.00%) 163398664 100% 0.00% 0% run_timer_softirq+0xb0 0.13% 0.88% 0.9us( 375us) 1.3us( 825us)(0.00%) 373228 99.1% 0.88% 0% schedule+0x260 0% 0% 0us 368227 100% 0% 0% schedule+0x680 0.02% 0.01% 0.2us( 44us) 19us( 224us)(0.00%) 265492 100% 0.01% 0% scheduler_tick+0x520 0.00% 0% 0.1us( 0.2us) 0us 40137 100% 0% 0% set_close_on_exec+0x30 0.00% 0% 0.2us( 13us) 0us 29924 100% 0% 0% set_task_comm+0x20 0% 0.03% 11us( 32us)(0.00%) 18665 100% 0.03% 0% sigprocmask+0x50 0.01% 0% 0.1us( 22us) 0us 286782 100% 0% 0% sys_close+0x30 0.00% 0% 0.2us( 28us) 0us 23247 100% 0% 0% sys_dup2+0x50 0.00% 0% 0.1us( 0.8us) 0us 149 100% 0% 0% task_dumpable+0x20 0% 0.41% 22us( 623us)(0.00%) 296779 99.6% 0.41% 0% task_rq_lock+0xa0 0% 0% 0us 4287 100% 0% 0% test_clear_page_dirty+0x90 0% 0% 0us 302 100% 0% 0% test_clear_page_writeback+0x90 0% 0% 0us 302 100% 0% 0% test_set_page_writeback+0x90 0.00% 0% 1.0us( 5.7us) 0us 1992 100% 0% 0% try_to_free_buffers+0x90 0.00% 0% 1176us(1190us) 0us 2 100% 0% 0% unmap_vmas+0x540 0.03% 0.05% 0.7us( 29us) 5.4us( 24us)(0.00%) 129360 100% 0.05% 0% vma_adjust+0x140 0.00% 0% 0.2us( 16us) 0us 67216 100% 0% 0% vma_adjust+0x2d0 0.06% 0.02% 0.7us( 749us) 6.1us( 36us)(0.00%) 255972 100% 0.02% 0% vma_link+0x60 0.00% 0% 0.4us( 12us) 0us 6326 100% 0% 0% vn_hold+0x70 0.00% 0% 0.1us( 0.6us) 0us 1207 100% 0% 0% vn_purge+0x30 0.00% 0% 0.1us( 3.3us) 0us 1207 100% 0% 0% vn_reclaim+0x100 0.00% 0% 0.1us( 0.3us) 0us 1207 100% 0% 0% vn_rele+0x130 0.00% 0% 0.1us( 3.6us) 0us 1207 100% 0% 0% vn_rele+0x70 0.00% 0% 0.0us( 0.1us) 0us 1236 100% 0% 0% vn_revalidate+0xf0 0.00% 0% 0.1us( 0.1us) 0us 1207 100% 0% 0% vn_wakeup+0x20 0% 0% 0us 29462 100% 0% 0% wait_for_completion+0x1d0 0% 0% 0us 29462 100% 0% 0% wait_for_completion+0x50 0% 0% 0us 30031 100% 0% 0% wait_task_zombie+0x170 0% 0% 0us 79650 100% 0% 0% worker_thread+0x2a0 0% 0% 0us 80491 100% 0% 0% worker_thread+0x430 0.00% 0% 0.7us( 1.3us) 0us 161 100% 0% 0% xfs_alloc_clear_busy+0x60 0.00% 0% 0.9us( 3.7us) 0us 162 100% 0% 0% xfs_alloc_mark_busy+0x60 0.00% 0% 0.3us( 1.5us) 0us 146 100% 0% 0% xfs_alloc_search_busy+0x60 0.00% 0% 0.1us( 1.2us) 0us 136 100% 0% 0% xfs_iextract+0xf0 0.05% 0% 17us( 130us) 0us 7869 100% 0% 0% xfs_iflush+0x3c0 0.00% 0% 0.4us( 28us) 0us 18630 100% 0% 0% xfs_iget_core+0x430 0.00% 0% 0.3us( 4.2us) 0us 98 100% 0% 0% xfs_map_blocks+0xf0 - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - RWLOCK READS HOLD MAX RDR BUSY PERIOD WAIT UTIL CON MEAN RDRS MEAN( MAX ) MEAN( MAX )( %CPU) TOTAL NOWAIT SPIN NAME 0.01% 7.9us( 186us)(0.00%) 922136 100% 0.01% *TOTAL* 0.00% 0% 0.2us 2 0.2us(1003us) 0us 30502 100% 0% binfmt_lock 0% 0us 30213 100% 0% search_binary_handler+0x80 0% 0us 289 100% 0% search_binary_handler+0x420 0.00% 0% 16.5us 1 16us( 42us) 0us 97 100% 0% file_systems_lock 0% 0us 97 100% 0% get_filesystem_list+0x30 29.5% 0.11% 0.8us 2 708us(40446ms) 7.9us( 186us)(0.00%) 114336 99.9% 0.11% tasklist_lock 0.01% 5.8us( 8.9us)(0.00%) 36542 100% 0.01% do_sigaction+0x260 0.17% 7.9us( 186us)(0.00%) 77267 99.8% 0.17% do_wait+0x160 0% 0us 371 100% 0% getrusage+0x40 0% 0us 149 100% 0% proc_pid_lookup+0x80 0% 0us 6 100% 0% session_of_pgrp+0x20 0% 0us 1 100% 0% wrap_mmu_context+0x70 59.2% 0% 143.5us 2 52ms(40446ms) 0us 3155 100% 0% vmlist_lock 0% 0us 3155 100% 0% get_vmalloc_info+0x40 0% 0us 30031 100% 0% copy_process+0x17d0 0% 0us 1043 100% 0% d_path+0x30 0% 0us 18468 100% 0% link_path_walk+0x1e50 0% 0us 24437 100% 0% link_path_walk+0xf80 0% 0us 673192 100% 0% path_lookup+0x60 0% 0us 6595 100% 0% sys_getcwd+0x80 0% 0us 19073 100% 0% xfs_iget_core+0x60 0% 0us 1207 100% 0% xfs_inode_incore+0x60 - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - RWLOCK WRITES HOLD WAIT (ALL) WAIT (WW) UTIL CON MEAN( MAX ) MEAN( MAX )( %CPU) MEAN( MAX ) TOTAL NOWAIT SPIN( WW ) NAME 0.05% 0.0us( 142us) 15us( 23us)(0.00%) 8.1us( 23us) 162200 100% 0.00%(0.04%) *TOTAL* 0.00% 0% 0.1us( 0.1us) 0us 0us 11 100% 0%( 0%) [0xe000003073709040] 0.00% 0% 0.1us( 0.1us) 0us 0us 11 100% 0%( 0%) neigh_periodic_timer+0x140 0.00% 0% 15us( 142us) 0us 0us 11 100% 0%( 0%) arp_tbl+0x17c 0.00% 0% 15us( 142us) 0us 0us 11 100% 0%( 0%) neigh_periodic_timer+0x40 0% 0% 0us 0us 10237 100% 0%( 0%) fasync_lock 0% 0% 0us 0us 10237 100% 0%( 0%) fasync_helper+0x80 0% 0.09% 15us( 23us)(0.00%) 8.1us( 23us) 90097 100% 0.01%(0.08%) tasklist_lock 0% 0.01% 3.7us( 3.7us)(0.00%) 3.7us( 3.7us) 30031 100% 0.01%(0.00%) copy_process+0xd40 0% 0.23% 15us( 23us)(0.00%) 8.3us( 23us) 30031 99.8% 0.02%(0.21%) exit_notify+0xd0 0% 0.03% 14us( 12us)(0.00%) 7.1us( 12us) 30031 100% 0%(0.03%) release_task+0xb0 0% 0% 0us 0us 4 100% 0%( 0%) sys_setpgid+0x90 0.00% 0% 0.1us( 10us) 0us 0us 43567 100% 0%( 0%) set_fs_pwd+0x20 0.00% 0% 0.1us( 1.1us) 0us 0us 136 100% 0%( 0%) xfs_finish_reclaim+0x30 0.00% 0% 0.1us( 1.3us) 0us 0us 136 100% 0%( 0%) xfs_iextract+0x30 0.00% 0% 0.1us( 9.7us) 0us 0us 18005 100% 0%( 0%) xfs_iget_core+0x230 _________________________________________________________________________________________________________________________ Number of read locks found=4 ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-09-14 17:52 ` Greg Edwards @ 2004-09-14 18:16 ` Manfred Spraul 2004-09-14 18:43 ` Greg Edwards 0 siblings, 1 reply; 35+ messages in thread From: Manfred Spraul @ 2004-09-14 18:16 UTC (permalink / raw) To: Greg Edwards Cc: Jesse Barnes, paulmck, Martin J. Bligh, hawkes, linux-kernel, wli Greg Edwards wrote: >Manfred, > >Lockstat output attached from 2.6.9-rc2 at 512p and 2.6.9-rc2 + your two >remaining RCU patches at 512p. kernbench was run without any arguments. > >The difference for RCU looks great. > > > Which value did you use for RCU_GROUP_SIZE? I'm not sure what's the optimal value for 512p - probably 32 or so. -- Manfred ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-09-14 18:16 ` Manfred Spraul @ 2004-09-14 18:43 ` Greg Edwards 2004-09-14 19:16 ` Manfred Spraul 0 siblings, 1 reply; 35+ messages in thread From: Greg Edwards @ 2004-09-14 18:43 UTC (permalink / raw) To: Manfred Spraul Cc: Jesse Barnes, paulmck, Martin J. Bligh, hawkes, linux-kernel, wli On Tue, Sep 14, 2004 at 08:16:24PM +0200, Manfred Spraul wrote: | Greg Edwards wrote: | | >Manfred, | > | >Lockstat output attached from 2.6.9-rc2 at 512p and 2.6.9-rc2 + your two | >remaining RCU patches at 512p. kernbench was run without any arguments. | > | >The difference for RCU looks great. | > | > | > | Which value did you use for RCU_GROUP_SIZE? I'm not sure what's the | optimal value for 512p - probably 32 or so. I used what was defined in the patch +#define RCU_GROUP_SIZE 2 I can try running with a couple different values and see how it looks. Greg ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-09-14 18:43 ` Greg Edwards @ 2004-09-14 19:16 ` Manfred Spraul 0 siblings, 0 replies; 35+ messages in thread From: Manfred Spraul @ 2004-09-14 19:16 UTC (permalink / raw) To: Greg Edwards Cc: Jesse Barnes, paulmck, Martin J. Bligh, hawkes, linux-kernel, wli Greg Edwards wrote: >| > >| Which value did you use for RCU_GROUP_SIZE? I'm not sure what's the >| optimal value for 512p - probably 32 or so. > >I used what was defined in the patch > >+#define RCU_GROUP_SIZE 2 > >I can try running with a couple different values and see how it looks. > > > Ok, that explains the lockstat: I've missed data on rcu_group_state.lock. I'd just use 32. The code uses a two-level bitmap and the group size specifies the size of the lower level. Thus you use right now a 2/256 split. Therefore you still trash the spinlock that protects the upper level. Group size 32 would generate a 32/16 split. -- Manfred ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 21:11 ` Jesse Barnes 2004-08-19 21:24 ` Jesse Barnes @ 2004-08-19 21:50 ` Ray Bryant 2004-08-19 22:00 ` Jesse Barnes 1 sibling, 1 reply; 35+ messages in thread From: Ray Bryant @ 2004-08-19 21:50 UTC (permalink / raw) To: Jesse Barnes; +Cc: Martin J. Bligh, hawkes, linux-kernel, wli Jesse, Jesse Barnes wrote: > On Thursday, August 19, 2004 2:25 pm, Martin J. Bligh wrote: > >>Does lockmeter not work for you? It's sitting in my tree still, and >>Andrew's last time I looked. > > > Ok, it seems to work at least a little (btw, oprofile cause the machine to be > unusable whenever a bunch of processes started up). > > I got a bunch of scary messages like these though: > > For cpu 140 entry 998 incremented kernel count=3 > Bad kernel cum_hold_ticks=-8658575876528 (FFFFF82004A91E50) for cpu=140 > index=999 > For cpu 140 entry 999 incremented kernel count=3 > > John, what does that mean? The lock contention was heavy, but I wouldn't > think that we'd overflow a 64 bit tick counter... > What it means is that a read lock was found at the end of the measurement interval in "read locked" state. This is due to a trick used to account for read lock hold times (rather than keeping track of the acquire and release times and then incrementing the hold time at release time as in: hold_time += (release_time - acquire_time); what is done instead is: hold_time -= acquire_time; when the lock is acquired, then hold_time += release_time; when the lock is released. If the lock is still being held at the end of the interval, then the 2nd hasn't been done, so the hold time appears negative. Anyway, the read lock handling is sufficiently busticated that we should probably just remove it. I have a patch someplace (years old) to fix this, but it never seemed to be important to anyone, so it is still unapplied. The stats for the spinlocks should be fine. > The output is attached (my mailer insists on wrapping it if I inline it). I > used 'lockstat -w'. > > Jesse > > -- Best Regards, Ray ----------------------------------------------- Ray Bryant 512-453-9679 (work) 512-507-7807 (cell) raybry@sgi.com raybry@austin.rr.com The box said: "Requires Windows 98 or better", so I installed Linux. ----------------------------------------------- ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 21:50 ` Ray Bryant @ 2004-08-19 22:00 ` Jesse Barnes 0 siblings, 0 replies; 35+ messages in thread From: Jesse Barnes @ 2004-08-19 22:00 UTC (permalink / raw) To: Ray Bryant; +Cc: Martin J. Bligh, hawkes, linux-kernel, wli On Thursday, August 19, 2004 5:50 pm, Ray Bryant wrote: > Anyway, the read lock handling is sufficiently busticated that we should > probably just remove it. I have a patch someplace (years old) to fix this, > but it never seemed to be important to anyone, so it is still unapplied. It would be nice if you resurrected it and sent it along to Andrew. He's had the lockmeter patch in his tree for awhile now, so having a good version there is probably a good idea. Thanks, Jesse ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 16:16 kernbench on 512p Jesse Barnes 2004-08-19 16:22 ` William Lee Irwin III 2004-08-19 16:29 ` David Mosberger @ 2004-08-19 23:03 ` William Lee Irwin III 2004-08-20 17:35 ` William Lee Irwin III 2004-08-20 0:56 ` remove dentry_open::file_ra_init_state() duplicated memset was " Marcelo Tosatti 3 siblings, 1 reply; 35+ messages in thread From: William Lee Irwin III @ 2004-08-19 23:03 UTC (permalink / raw) To: Jesse Barnes; +Cc: linux-kernel On Thu, Aug 19, 2004 at 12:16:33PM -0400, Jesse Barnes wrote: > This is a 64p profile only. If I set the prof_cpu_mask to include all 512 > CPUs, the system livelocks. I reset the counter right after the warmup run, > partly through the half load run, and collected it after a few runs were > complete. Not tremendously intelligent, as concurrent readers of /proc/profile can render each other's results gibberish, however, this should mitigate some of the cacheline bouncing of prof_buffer. Some kind of proper IO should be possible given sufficient effort, but I gave up immediately when my first attempt didn't work, and this should be enough for getting /proc/profile to stop bouncing madly for users that can tolerate the concurrent IO constraint. I suppose that in principle one could hackishly guard collation and copying of prof_buffer with a semaphore in the per-cpu case. I'll work on fixing this eventually. Use perpcu_profile on the kernel command line to activate the feature. Index: mm2-2.6.8.1/kernel/profile.c =================================================================== --- mm2-2.6.8.1.orig/kernel/profile.c 2004-08-19 13:22:11.000000000 -0700 +++ mm2-2.6.8.1/kernel/profile.c 2004-08-19 15:11:40.000000000 -0700 @@ -10,12 +10,14 @@ #include <linux/mm.h> #include <linux/cpumask.h> #include <linux/profile.h> +#include <linux/percpu.h> #include <asm/sections.h> static atomic_t *prof_buffer; static unsigned long prof_len, prof_shift; -static int prof_on; +static int prof_on, percpu_profile; static cpumask_t prof_cpu_mask = CPU_MASK_ALL; +static DEFINE_PER_CPU(atomic_t *, cpu_prof_buffer); static int __init profile_setup(char * str) { @@ -37,15 +39,35 @@ } __setup("profile=", profile_setup); +static int __init profile_setup_percpu(char *str) +{ + percpu_profile = 1; + return 1; +} +__setup("percpu_profile", profile_setup_percpu); + void __init profile_init(void) { + size_t len; + int cpu; + if (!prof_on) return; /* only text is profiled */ prof_len = (_etext - _stext) >> prof_shift; - prof_buffer = alloc_bootmem(prof_len*sizeof(atomic_t)); + len = prof_len * sizeof(atomic_t); + prof_buffer = alloc_bootmem(len); + for_each_cpu(cpu) { + if (!percpu_profile) + per_cpu(cpu_prof_buffer, cpu) = prof_buffer; + else { + pg_data_t *pgdat = NODE_DATA(cpu_to_node(cpu)); + per_cpu(cpu_prof_buffer, cpu) + = alloc_bootmem_node(pgdat, len); + } + } } /* Profile event notifications */ @@ -165,11 +187,15 @@ void profile_hit(int type, void *__pc) { unsigned long pc; + atomic_t *buf; - if (prof_on != type || !prof_buffer) + if (prof_on != type) return; pc = ((unsigned long)__pc - (unsigned long)_stext) >> prof_shift; - atomic_inc(&prof_buffer[min(pc, prof_len - 1)]); + buf = per_cpu(cpu_prof_buffer, get_cpu()); + if (buf) + atomic_inc(&buf[min(pc, prof_len - 1)]); + put_cpu(); } void profile_tick(int type, struct pt_regs *regs) @@ -223,6 +249,21 @@ entry->write_proc = prof_cpu_mask_write_proc; } +static void collate_per_cpu_profiles(void) +{ + unsigned long i; + + for (i = 0; i < prof_len; ++i) { + int cpu; + + atomic_set(&prof_buffer[i], 0); + for_each_online_cpu(cpu) { + atomic_t *buf = per_cpu(cpu_prof_buffer, cpu); + atomic_add(atomic_read(&buf[i]), &prof_buffer[i]); + } + } +} + /* * This function accesses profiling information. The returned data is * binary: the sampling step and the actual contents of the profile @@ -247,6 +288,8 @@ put_user(*((char *)(&sample_step)+p),buf); buf++; p++; count--; read++; } + if (percpu_profile) + collate_per_cpu_profiles(); pnt = (char *)prof_buffer + p - sizeof(atomic_t); if (copy_to_user(buf,(void *)pnt,count)) return -EFAULT; @@ -278,7 +321,15 @@ } #endif - memset(prof_buffer, 0, prof_len * sizeof(atomic_t)); + if (percpu_profile) { + int cpu; + + for_each_online_cpu(cpu) { + atomic_t *buf = per_cpu(cpu_prof_buffer, cpu); + memset(buf, 0, prof_len * sizeof(atomic_t)); + } + } else + memset(prof_buffer, 0, prof_len * sizeof(atomic_t)); return count; } ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: kernbench on 512p 2004-08-19 23:03 ` William Lee Irwin III @ 2004-08-20 17:35 ` William Lee Irwin III 0 siblings, 0 replies; 35+ messages in thread From: William Lee Irwin III @ 2004-08-20 17:35 UTC (permalink / raw) To: Jesse Barnes, linux-kernel On Thu, Aug 19, 2004 at 04:03:15PM -0700, William Lee Irwin III wrote: > Not tremendously intelligent, as concurrent readers of /proc/profile > can render each other's results gibberish, however, this should > mitigate some of the cacheline bouncing of prof_buffer. > Some kind of proper IO should be possible given sufficient effort, but > I gave up immediately when my first attempt didn't work, and this > should be enough for getting /proc/profile to stop bouncing madly for > users that can tolerate the concurrent IO constraint. I suppose that > in principle one could hackishly guard collation and copying of > prof_buffer with a semaphore in the per-cpu case. I'll work on fixing > this eventually. > Use perpcu_profile on the kernel command line to activate the feature. This fixes the degenerate collate_per_cpu_profiles() behavior jbarnes saw with this patch alone. Index: mm2-2.6.8.1/kernel/profile.c =================================================================== --- mm2-2.6.8.1.orig/kernel/profile.c 2004-08-19 15:11:40.000000000 -0700 +++ mm2-2.6.8.1/kernel/profile.c 2004-08-20 09:32:08.986630798 -0700 @@ -251,16 +251,15 @@ static void collate_per_cpu_profiles(void) { - unsigned long i; + int cpu; - for (i = 0; i < prof_len; ++i) { - int cpu; + memset(prof_buffer, 0, prof_len * sizeof(atomic_t)); + for_each_online_cpu(cpu) { + unsigned long i; + atomic_t *buf per_cpu(cpu_prof_buffer, cpu); - atomic_set(&prof_buffer[i], 0); - for_each_online_cpu(cpu) { - atomic_t *buf = per_cpu(cpu_prof_buffer, cpu); - atomic_add(atomic_read(&buf[i]), &prof_buffer[i]); - } + for (i = 0; i < prof_len; ++i) + prof_buffer[i].counter += atomic_read(&buf[i]); } } ^ permalink raw reply [flat|nested] 35+ messages in thread
* remove dentry_open::file_ra_init_state() duplicated memset was Re: kernbench on 512p 2004-08-19 16:16 kernbench on 512p Jesse Barnes ` (2 preceding siblings ...) 2004-08-19 23:03 ` William Lee Irwin III @ 2004-08-20 0:56 ` Marcelo Tosatti 2004-08-20 6:21 ` Andrew Morton 3 siblings, 1 reply; 35+ messages in thread From: Marcelo Tosatti @ 2004-08-20 0:56 UTC (permalink / raw) To: Jesse Barnes, akpm; +Cc: linux-kernel On Thu, Aug 19, 2004 at 12:16:33PM -0400, Jesse Barnes wrote: > Here's the kernel profile. It would be nice if the patch to show which lock > is contended got included. I think it was discussed awhile back, but I don't > have one against the newly merged profiling code. > > [root@ascender root]# readprofile -m System.map | sort -nr | head -30 > 208218076 total 30.1677 > 90036167 ia64_pal_call_static 468938.3698 > 88140492 default_idle 229532.5312 > 10312592 ia64_save_scratch_fpregs 161134.2500 > 10306777 ia64_load_scratch_fpregs 161043.3906 > 8723555 ia64_spinlock_contention 90870.3646 > 121385 rcu_check_quiescent_state 316.1068 > 40464 file_move 180.6429 > 32374 file_kill 144.5268 > 25316 atomic_dec_and_lock 98.8906 > 24814 clear_page 155.0875 > 17709 file_ra_state_init 110.6813 This is pretty high. Andi says its probably not due to this function itself, but for some other reason, like cache trashing caused, accidentally, by it. But anyway, investigation of file_ra_state_init() shows that its called from dentry_open()... it does a memset(ra, 0, sizeof(*ra)), which is not needed, because get_empty_filp() already memset's the whole "struct file" to 0. So this patch creates a __file_ra_state_init() function, which initializes the file_ra_state fields, without the memset. file_ra_state_init() does the memset + its __ counterpart. Pretty straightforward and simple. Against 2.6.8.1-mm2, Andrew, please apply. Jesse, if you could give it a shot and rerun the profile. diff -Nur --exclude='*.orig' linux-2.6.8.orig/fs/open.c linux-2.6.8/fs/open.c --- linux-2.6.8.orig/fs/open.c 2004-08-14 02:36:13.000000000 -0300 +++ linux-2.6.8/fs/open.c 2004-08-19 22:38:48.000000000 -0300 @@ -803,7 +803,7 @@ } f->f_flags &= ~(O_CREAT | O_EXCL | O_NOCTTY | O_TRUNC); - file_ra_state_init(&f->f_ra, f->f_mapping->host->i_mapping); + __file_ra_state_init(&f->f_ra, f->f_mapping->host->i_mapping); /* NB: we're sure to have correct a_ops only after f_op->open */ if (f->f_flags & O_DIRECT) { diff -Nur --exclude='*.orig' linux-2.6.8.orig/include/linux/fs.h linux-2.6.8/include/linux/fs.h --- linux-2.6.8.orig/include/linux/fs.h 2004-08-19 22:35:49.000000000 -0300 +++ linux-2.6.8/include/linux/fs.h 2004-08-19 22:39:55.000000000 -0300 @@ -1520,7 +1520,10 @@ struct file_ra_state *, struct file *, loff_t *, read_descriptor_t *, read_actor_t); extern void +__file_ra_state_init(struct file_ra_state *ra, struct address_space *mapping); +extern void file_ra_state_init(struct file_ra_state *ra, struct address_space *mapping); + extern ssize_t generic_file_direct_IO(int rw, struct kiocb *iocb, const struct iovec *iov, loff_t offset, unsigned long nr_segs); extern ssize_t generic_file_readv(struct file *filp, const struct iovec *iov, diff -Nur --exclude='*.orig' linux-2.6.8.orig/mm/readahead.c linux-2.6.8/mm/readahead.c --- linux-2.6.8.orig/mm/readahead.c 2004-08-19 22:35:50.000000000 -0300 +++ linux-2.6.8/mm/readahead.c 2004-08-19 22:37:49.000000000 -0300 @@ -30,13 +30,22 @@ /* * Initialise a struct file's readahead state */ + void -file_ra_state_init(struct file_ra_state *ra, struct address_space *mapping) +__file_ra_state_init(struct file_ra_state *ra, struct address_space *mapping) { - memset(ra, 0, sizeof(*ra)); ra->ra_pages = mapping->backing_dev_info->ra_pages; ra->average = ra->ra_pages / 2; } + +void +file_ra_state_init(struct file_ra_state *ra, struct address_space *mapping) +{ + memset(ra, 0, sizeof(*ra)); + __file_ra_state_init(ra, mapping); +} + +EXPORT_SYMBOL(__file_ra_state_init); EXPORT_SYMBOL(file_ra_state_init); /* ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: remove dentry_open::file_ra_init_state() duplicated memset was Re: kernbench on 512p 2004-08-20 0:56 ` remove dentry_open::file_ra_init_state() duplicated memset was " Marcelo Tosatti @ 2004-08-20 6:21 ` Andrew Morton 2004-08-20 7:28 ` Marcelo Tosatti 0 siblings, 1 reply; 35+ messages in thread From: Andrew Morton @ 2004-08-20 6:21 UTC (permalink / raw) To: Marcelo Tosatti; +Cc: jbarnes, linux-kernel Marcelo Tosatti <marcelo.tosatti@cyclades.com> wrote: > > So this patch creates a __file_ra_state_init() function, which initializes > the file_ra_state fields, without the memset. > > file_ra_state_init() does the memset + its __ counterpart. Seems unnecessarily fiddly. How about this? --- 25/mm/readahead.c~file_ra_state_init-speedup 2004-08-19 23:20:11.695876032 -0700 +++ 25-akpm/mm/readahead.c 2004-08-19 23:20:42.077257360 -0700 @@ -28,12 +28,12 @@ struct backing_dev_info default_backing_ EXPORT_SYMBOL_GPL(default_backing_dev_info); /* - * Initialise a struct file's readahead state + * Initialise a struct file's readahead state. Assumes that the caller has + * memset *ra to zero. */ void file_ra_state_init(struct file_ra_state *ra, struct address_space *mapping) { - memset(ra, 0, sizeof(*ra)); ra->ra_pages = mapping->backing_dev_info->ra_pages; ra->average = ra->ra_pages / 2; } diff -puN fs/nfsd/vfs.c~file_ra_state_init-speedup fs/nfsd/vfs.c --- 25/fs/nfsd/vfs.c~file_ra_state_init-speedup 2004-08-19 23:20:11.713873296 -0700 +++ 25-akpm/fs/nfsd/vfs.c 2004-08-19 23:21:05.721662864 -0700 @@ -771,6 +771,7 @@ nfsd_get_raparms(dev_t dev, ino_t ino, s ra = *frap; ra->p_dev = dev; ra->p_ino = ino; + memset(&ra->p_ra, 0, sizeof(ra->p_ra)); file_ra_state_init(&ra->p_ra, mapping); found: if (rap != &raparm_cache) { _ ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: remove dentry_open::file_ra_init_state() duplicated memset was Re: kernbench on 512p 2004-08-20 6:21 ` Andrew Morton @ 2004-08-20 7:28 ` Marcelo Tosatti 2004-08-20 8:34 ` Andrew Morton 0 siblings, 1 reply; 35+ messages in thread From: Marcelo Tosatti @ 2004-08-20 7:28 UTC (permalink / raw) To: Andrew Morton; +Cc: jbarnes, linux-kernel On Thu, Aug 19, 2004 at 11:21:45PM -0700, Andrew Morton wrote: > Marcelo Tosatti <marcelo.tosatti@cyclades.com> wrote: > > > > So this patch creates a __file_ra_state_init() function, which initializes > > the file_ra_state fields, without the memset. > > > > file_ra_state_init() does the memset + its __ counterpart. > > Seems unnecessarily fiddly. How about this? Thats cleaner yep. :) > --- 25/mm/readahead.c~file_ra_state_init-speedup 2004-08-19 23:20:11.695876032 -0700 > +++ 25-akpm/mm/readahead.c 2004-08-19 23:20:42.077257360 -0700 > @@ -28,12 +28,12 @@ struct backing_dev_info default_backing_ > EXPORT_SYMBOL_GPL(default_backing_dev_info); > > /* > - * Initialise a struct file's readahead state > + * Initialise a struct file's readahead state. Assumes that the caller has > + * memset *ra to zero. > */ > void > file_ra_state_init(struct file_ra_state *ra, struct address_space *mapping) > { > - memset(ra, 0, sizeof(*ra)); > ra->ra_pages = mapping->backing_dev_info->ra_pages; > ra->average = ra->ra_pages / 2; > } > diff -puN fs/nfsd/vfs.c~file_ra_state_init-speedup fs/nfsd/vfs.c > --- 25/fs/nfsd/vfs.c~file_ra_state_init-speedup 2004-08-19 23:20:11.713873296 -0700 > +++ 25-akpm/fs/nfsd/vfs.c 2004-08-19 23:21:05.721662864 -0700 > @@ -771,6 +771,7 @@ nfsd_get_raparms(dev_t dev, ino_t ino, s > ra = *frap; > ra->p_dev = dev; > ra->p_ino = ino; > + memset(&ra->p_ra, 0, sizeof(ra->p_ra)); > file_ra_state_init(&ra->p_ra, mapping); > found: > if (rap != &raparm_cache) { > _ ^ permalink raw reply [flat|nested] 35+ messages in thread
* Re: remove dentry_open::file_ra_init_state() duplicated memset was Re: kernbench on 512p 2004-08-20 7:28 ` Marcelo Tosatti @ 2004-08-20 8:34 ` Andrew Morton 0 siblings, 0 replies; 35+ messages in thread From: Andrew Morton @ 2004-08-20 8:34 UTC (permalink / raw) To: Marcelo Tosatti; +Cc: jbarnes, linux-kernel Marcelo Tosatti <marcelo.tosatti@cyclades.com> wrote: > > On Thu, Aug 19, 2004 at 11:21:45PM -0700, Andrew Morton wrote: > > Marcelo Tosatti <marcelo.tosatti@cyclades.com> wrote: > > > > > > So this patch creates a __file_ra_state_init() function, which initializes > > > the file_ra_state fields, without the memset. > > > > > > file_ra_state_init() does the memset + its __ counterpart. > > > > Seems unnecessarily fiddly. How about this? > > Thats cleaner yep. :) It got even cleaner - Neil has just nuked the NFS callsite. --- 25/mm/readahead.c~file_ra_state_init-speedup 2004-08-20 00:03:19.979397128 -0700 +++ 25-akpm/mm/readahead.c 2004-08-20 00:04:25.159488248 -0700 @@ -28,16 +28,15 @@ struct backing_dev_info default_backing_ EXPORT_SYMBOL_GPL(default_backing_dev_info); /* - * Initialise a struct file's readahead state + * Initialise a struct file's readahead state. Assumes that the caller has + * memset *ra to zero. */ void file_ra_state_init(struct file_ra_state *ra, struct address_space *mapping) { - memset(ra, 0, sizeof(*ra)); ra->ra_pages = mapping->backing_dev_info->ra_pages; ra->average = ra->ra_pages / 2; } -EXPORT_SYMBOL(file_ra_state_init); /* * Return max readahead size for this inode in number-of-pages. _ ^ permalink raw reply [flat|nested] 35+ messages in thread
end of thread, other threads:[~2004-09-14 19:19 UTC | newest] Thread overview: 35+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2004-08-19 16:16 kernbench on 512p Jesse Barnes 2004-08-19 16:22 ` William Lee Irwin III 2004-08-19 16:29 ` David Mosberger 2004-08-19 16:37 ` Jesse Barnes 2004-08-19 16:40 ` David Mosberger 2004-08-19 17:55 ` Alan Cox 2004-08-20 7:53 ` David Mosberger 2004-08-19 18:25 ` Martin J. Bligh 2004-08-19 18:42 ` Jesse Barnes 2004-08-19 21:11 ` Jesse Barnes 2004-08-19 21:24 ` Jesse Barnes 2004-08-19 21:56 ` Martin J. Bligh 2004-08-20 19:36 ` Maneesh Soni 2004-08-19 23:38 ` Paul E. McKenney 2004-08-20 0:16 ` Jesse Barnes 2004-08-20 15:57 ` Paul E. McKenney 2004-08-20 17:24 ` Jesse Barnes 2004-08-20 19:22 ` Manfred Spraul 2004-08-20 20:19 ` Manfred Spraul 2004-08-23 21:23 ` Jesse Barnes 2004-08-23 23:13 ` Jesse Barnes 2004-09-10 19:01 ` Greg Edwards 2004-09-13 18:21 ` Manfred Spraul 2004-09-14 17:52 ` Greg Edwards 2004-09-14 18:16 ` Manfred Spraul 2004-09-14 18:43 ` Greg Edwards 2004-09-14 19:16 ` Manfred Spraul 2004-08-19 21:50 ` Ray Bryant 2004-08-19 22:00 ` Jesse Barnes 2004-08-19 23:03 ` William Lee Irwin III 2004-08-20 17:35 ` William Lee Irwin III 2004-08-20 0:56 ` remove dentry_open::file_ra_init_state() duplicated memset was " Marcelo Tosatti 2004-08-20 6:21 ` Andrew Morton 2004-08-20 7:28 ` Marcelo Tosatti 2004-08-20 8:34 ` Andrew Morton
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox