public inbox for linux-kernel@vger.kernel.org
 help / color / mirror / Atom feed
* Very poor performance with 2.6.4
@ 2004-03-28 20:02 Andreas Hartmann
  2004-03-28 20:24 ` Matt H.
                   ` (2 more replies)
  0 siblings, 3 replies; 15+ messages in thread
From: Andreas Hartmann @ 2004-03-28 20:02 UTC (permalink / raw)
  To: linux-kernel

Hello!

I tested kernel 2.6.4. While compiling kdelibs and kdebase, I felt, that
kernel 2.6 seems to be slower than 2.4.25.

So I did some tests to compare the performance directly. Therefore I
rebooted for everey test in init 2 (no X).

I locally compiled 2.6.5rc2 3 times under 2.6.4 and under 2.4.25 on a
reiserfs LVM partition, which resides onto a IDE HD (using DMA) and got
the following result:

In the middle, compiling under kernel 2.6.4 tooks 9.3% more real time than
under 2.4.25.
The user-processortime is about the same, but the system-processortime is
under 2.6.4 32.9% higher than under 2.4.25.


Now, I switched off preemption. But the performance isn't much better:
8.8% (9.3% with preemption) more real-time compared to 2.4.25 and 28%
(32.9% with preepmtion) more system-time.



Does anybody know, how to get the same performance under 2.6.4 (or even
better) as under 2.4.25?


My hardware:
AMD Athlon(tm) XP 2000+

00:00.0 Host bridge: VIA Technologies, Inc. VT8366/A/7 [Apollo KT266/A/333]
00:01.0 PCI bridge: VIA Technologies, Inc. VT8366/A/7 [Apollo KT266/A/333 AGP]
00:09.0 Ethernet controller: Silicon Integrated Systems [SiS] SiS900
10/100 Ethernet (rev 02)
00:0c.0 Ethernet controller: Intel Corp. 82557/8/9 [Ethernet Pro 100] (rev 0c)
00:10.0 USB Controller: VIA Technologies, Inc. USB (rev 80)
00:10.1 USB Controller: VIA Technologies, Inc. USB (rev 80)
00:10.2 USB Controller: VIA Technologies, Inc. USB (rev 80)
00:10.3 USB Controller: VIA Technologies, Inc. USB 2.0 (rev 82)
00:11.0 ISA bridge: VIA Technologies, Inc. VT8235 ISA Bridge
00:11.1 IDE interface: VIA Technologies, Inc.
VT82C586A/B/VT82C686/A/B/VT8233/A/C/VT8235 PIPC Bus Master IDE (rev 06)
00:11.5 Multimedia audio controller: VIA Technologies, Inc. VT8233/A/8235
AC97 Audio Controller (rev 50)
01:00.0 VGA compatible controller: ATI Technologies Inc Rage 128 PF/PRO
AGP 4x TMDS


Regards,
Andreas Hartmann


^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
  2004-03-28 20:02 Very poor performance with 2.6.4 Andreas Hartmann
@ 2004-03-28 20:24 ` Matt H.
  2004-03-28 21:11 ` Sasa U
  2004-03-29  4:07 ` Andrew Morton
  2 siblings, 0 replies; 15+ messages in thread
From: Matt H. @ 2004-03-28 20:24 UTC (permalink / raw)
  To: linux-kernel; +Cc: Andreas Hartmann

Have you tried the -mm tree yet ? 

If not you should. 

Matt

On Sunday 28 March 2004 1:02 pm, Andreas Hartmann wrote:
> Hello!
>
> I tested kernel 2.6.4. While compiling kdelibs and kdebase, I felt, that
> kernel 2.6 seems to be slower than 2.4.25.
>
> So I did some tests to compare the performance directly. Therefore I
> rebooted for everey test in init 2 (no X).
>
> I locally compiled 2.6.5rc2 3 times under 2.6.4 and under 2.4.25 on a
> reiserfs LVM partition, which resides onto a IDE HD (using DMA) and got
> the following result:
>
> In the middle, compiling under kernel 2.6.4 tooks 9.3% more real time than
> under 2.4.25.
> The user-processortime is about the same, but the system-processortime is
> under 2.6.4 32.9% higher than under 2.4.25.
>
>
> Now, I switched off preemption. But the performance isn't much better:
> 8.8% (9.3% with preemption) more real-time compared to 2.4.25 and 28%
> (32.9% with preepmtion) more system-time.
>
>
>
> Does anybody know, how to get the same performance under 2.6.4 (or even
> better) as under 2.4.25?
>
>
> My hardware:
> AMD Athlon(tm) XP 2000+
>
> 00:00.0 Host bridge: VIA Technologies, Inc. VT8366/A/7 [Apollo KT266/A/333]
> 00:01.0 PCI bridge: VIA Technologies, Inc. VT8366/A/7 [Apollo KT266/A/333
> AGP] 00:09.0 Ethernet controller: Silicon Integrated Systems [SiS] SiS900
> 10/100 Ethernet (rev 02)
> 00:0c.0 Ethernet controller: Intel Corp. 82557/8/9 [Ethernet Pro 100] (rev
> 0c) 00:10.0 USB Controller: VIA Technologies, Inc. USB (rev 80)
> 00:10.1 USB Controller: VIA Technologies, Inc. USB (rev 80)
> 00:10.2 USB Controller: VIA Technologies, Inc. USB (rev 80)
> 00:10.3 USB Controller: VIA Technologies, Inc. USB 2.0 (rev 82)
> 00:11.0 ISA bridge: VIA Technologies, Inc. VT8235 ISA Bridge
> 00:11.1 IDE interface: VIA Technologies, Inc.
> VT82C586A/B/VT82C686/A/B/VT8233/A/C/VT8235 PIPC Bus Master IDE (rev 06)
> 00:11.5 Multimedia audio controller: VIA Technologies, Inc. VT8233/A/8235
> AC97 Audio Controller (rev 50)
> 01:00.0 VGA compatible controller: ATI Technologies Inc Rage 128 PF/PRO
> AGP 4x TMDS
>
>
> Regards,
> Andreas Hartmann
>
> -
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
  2004-03-28 20:02 Very poor performance with 2.6.4 Andreas Hartmann
  2004-03-28 20:24 ` Matt H.
@ 2004-03-28 21:11 ` Sasa U
  2004-03-29  4:07 ` Andrew Morton
  2 siblings, 0 replies; 15+ messages in thread
From: Sasa U @ 2004-03-28 21:11 UTC (permalink / raw)
  To: linux-kernel

Hi,

I also have problems with speed under 2.6 ...

However, disk I/O is slower under 2.6 ... comparing to 2.4.

I talked to some people about it .. and they have the same experience ...

Aksed once about that on this mailing list, but didn't get answers ...


Regards
S

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
       [not found] <1EOM0-3oS-17@gated-at.bofh.it>
@ 2004-03-28 22:47 ` Andi Kleen
  0 siblings, 0 replies; 15+ messages in thread
From: Andi Kleen @ 2004-03-28 22:47 UTC (permalink / raw)
  To: Andreas Hartmann; +Cc: linux-kernel

Andreas Hartmann <andihartmann@freenet.de> writes:
>
> Now, I switched off preemption. But the performance isn't much better:
> 8.8% (9.3% with preemption) more real-time compared to 2.4.25 and 28%
> (32.9% with preepmtion) more system-time.

Install oprofile and do a profile run on the 2.6 kernel. This should
tell you where the system time is wasted. Post the results on this
list.

-Andi




^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
  2004-03-28 20:02 Very poor performance with 2.6.4 Andreas Hartmann
  2004-03-28 20:24 ` Matt H.
  2004-03-28 21:11 ` Sasa U
@ 2004-03-29  4:07 ` Andrew Morton
  2004-03-29  6:16   ` Andreas Hartmann
  2004-03-29 17:41   ` Andreas Hartmann
  2 siblings, 2 replies; 15+ messages in thread
From: Andrew Morton @ 2004-03-29  4:07 UTC (permalink / raw)
  To: Andreas Hartmann; +Cc: linux-kernel

Andreas Hartmann <andihartmann@freenet.de> wrote:
>
> I tested kernel 2.6.4. While compiling kdelibs and kdebase, I felt, that
>  kernel 2.6 seems to be slower than 2.4.25.
> 
>  So I did some tests to compare the performance directly. Therefore I
>  rebooted for everey test in init 2 (no X).
> 
>  I locally compiled 2.6.5rc2 3 times under 2.6.4 and under 2.4.25 on a
>  reiserfs LVM partition, which resides onto a IDE HD (using DMA) and got
>  the following result:
> 
>  In the middle, compiling under kernel 2.6.4 tooks 9.3% more real time than
>  under 2.4.25.
>  The user-processortime is about the same, but the system-processortime is
>  under 2.6.4 32.9% higher than under 2.4.25.

Try mounting your reiserfs filesystems with the `-o nolargeio=1' option.

If that doesn't help, please run a comparative kernel profile.  See
Documentation/basic_profiling.txt.

Thanks.

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
  2004-03-29  4:07 ` Andrew Morton
@ 2004-03-29  6:16   ` Andreas Hartmann
  2004-03-29 14:23     ` Chris Mason
  2004-03-29 17:41   ` Andreas Hartmann
  1 sibling, 1 reply; 15+ messages in thread
From: Andreas Hartmann @ 2004-03-29  6:16 UTC (permalink / raw)
  To: Andrew Morton; +Cc: linux-kernel

Andrew Morton wrote:
> Andreas Hartmann <andihartmann@freenet.de> wrote:
>>
>> I tested kernel 2.6.4. While compiling kdelibs and kdebase, I felt, that
>>  kernel 2.6 seems to be slower than 2.4.25.
>> 
>>  So I did some tests to compare the performance directly. Therefore I
>>  rebooted for everey test in init 2 (no X).
>> 
>>  I locally compiled 2.6.5rc2 3 times under 2.6.4 and under 2.4.25 on a
>>  reiserfs LVM partition, which resides onto a IDE HD (using DMA) and got
>>  the following result:
>> 
>>  In the middle, compiling under kernel 2.6.4 tooks 9.3% more real time than
>>  under 2.4.25.
>>  The user-processortime is about the same, but the system-processortime is
>>  under 2.6.4 32.9% higher than under 2.4.25.
> 
> Try mounting your reiserfs filesystems with the `-o nolargeio=1' option.

This didn't help.

> 
> If that doesn't help, please run a comparative kernel profile.  See
> Documentation/basic_profiling.txt.

I'll do this next.


Regards,
Andreas Hartmann

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
  2004-03-29  6:16   ` Andreas Hartmann
@ 2004-03-29 14:23     ` Chris Mason
  2004-03-29 19:35       ` Andreas Hartmann
                         ` (2 more replies)
  0 siblings, 3 replies; 15+ messages in thread
From: Chris Mason @ 2004-03-29 14:23 UTC (permalink / raw)
  To: Andreas Hartmann; +Cc: Andrew Morton, linux-kernel

On Mon, 2004-03-29 at 01:16, Andreas Hartmann wrote:
> Andrew Morton wrote:
> > Andreas Hartmann <andihartmann@freenet.de> wrote:
> >>
> >> I tested kernel 2.6.4. While compiling kdelibs and kdebase, I felt, that
> >>  kernel 2.6 seems to be slower than 2.4.25.
> >> 
> >>  So I did some tests to compare the performance directly. Therefore I
> >>  rebooted for everey test in init 2 (no X).
> >> 
> >>  I locally compiled 2.6.5rc2 3 times under 2.6.4 and under 2.4.25 on a
> >>  reiserfs LVM partition, which resides onto a IDE HD (using DMA) and got
> >>  the following result:
> >> 
> >>  In the middle, compiling under kernel 2.6.4 tooks 9.3% more real time than
> >>  under 2.4.25.
> >>  The user-processortime is about the same, but the system-processortime is
> >>  under 2.6.4 32.9% higher than under 2.4.25.
> > 
> > Try mounting your reiserfs filesystems with the `-o nolargeio=1' option.
> 
> This didn't help.
> 
> > 
> > If that doesn't help, please run a comparative kernel profile.  See
> > Documentation/basic_profiling.txt.
> 
> I'll do this next.

You might also want to try 2.6.5-rc2 which has a set of reiserfs fixes
from 2.4.x.  I'm hoping those will clean things up for you.

2.6.5-rc2-mm3 and higher have a number of other reiserfs performance
fixes, but most of those were not in 2.4.  Trying them out will
complicate the picture (although I'm still interested in numbers from
-mm).

-chris



^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
  2004-03-29  4:07 ` Andrew Morton
  2004-03-29  6:16   ` Andreas Hartmann
@ 2004-03-29 17:41   ` Andreas Hartmann
  1 sibling, 0 replies; 15+ messages in thread
From: Andreas Hartmann @ 2004-03-29 17:41 UTC (permalink / raw)
  To: Andrew Morton; +Cc: linux-kernel

Andrew Morton wrote:
> Andreas Hartmann <andihartmann@freenet.de> wrote:
>>
>> I tested kernel 2.6.4. While compiling kdelibs and kdebase, I felt, that
>>  kernel 2.6 seems to be slower than 2.4.25.
>> 
>>  So I did some tests to compare the performance directly. Therefore I
>>  rebooted for everey test in init 2 (no X).
>> 
>>  I locally compiled 2.6.5rc2 3 times under 2.6.4 and under 2.4.25 on a
>>  reiserfs LVM partition, which resides onto a IDE HD (using DMA) and got
>>  the following result:
>> 
>>  In the middle, compiling under kernel 2.6.4 tooks 9.3% more real time than
>>  under 2.4.25.
>>  The user-processortime is about the same, but the system-processortime is
>>  under 2.6.4 32.9% higher than under 2.4.25.

[...]

> If that doesn't help, please run a comparative kernel profile.  See
> Documentation/basic_profiling.txt.

Ok. Here it is:

Kernel 2.4.25 / make of kernel 2.6.5.rc2:

   5617 default_idle                             117.0208
      4 __switch_to                                0.0179
      1 sys_sigreturn                              0.0042
      1 do_signal                                  0.0015
     28 system_call                                0.5000
      2 ret_from_sys_call                          0.1176
      3 ret_from_exception                         0.1200
      2 error_code                                 0.0333
     14 device_not_available                       0.2917
      3 math_state_restore                         0.0469
      1 do_gettimeofday                            0.0104
      6 old_mmap                                   0.0221
     10 __constant_copy_from_user                  0.0645
      1 save_init_fpu                              0.0156
      9 kernel_fpu_begin                           0.1406
     11 restore_fpu                                0.3438
      1 do_check_pgt_cache                         0.0069
    222 do_page_fault                              0.1769
     19 schedule                                   0.0233
      2 __wake_up                                  0.0179
      1 complete                                   0.0089
      1 remove_wait_queue                          0.0156
      4 copy_files                                 0.0058
      3 do_fork                                    0.0016
      3 __constant_c_and_count_memset              0.0234
      2 dup_mmap                                   0.0051
      7 exit_notify                                0.0095
      1 sys_wait4                                  0.0010
     71 do_softirq                                 0.4437
      2 tasklet_hi_action                          0.0179
      3 bh_action                                  0.0469
      3 timer_bh                                   0.0144
      8 run_timer_list                             0.0227
      1 exit_sighand                               0.0104
      2 sys_rt_sigprocmask                         0.0048
      1 do_sigaction                               0.0037
      2 sys_rt_sigaction                           0.0104
      1 sys_ni_syscall                             0.0625
      8 supplemental_group_member                  0.1250
      1 in_group_p                                 0.0208
      1 sys_newuname                               0.0104
      2 __constant_copy_to_user                    0.0139
     10 __free_pte                                 0.1042
      6 clear_page_tables                          0.0375
     15 copy_page_range                            0.0361
      9 zap_page_range                             0.0375
      5 do_wp_page                                 0.0098
     65 do_anonymous_page                          0.2708
     36 do_no_page                                 0.0804
     42 handle_mm_fault                            0.1641
     28 pte_alloc                                  0.1591
     33 zap_pte_range                              0.1279
      6 vm_enough_memory                           0.0625
     10 find_vma_prepare                           0.0893
      5 __vma_link                                 0.0260
      5 vma_merge                                  0.0223
     31 do_mmap_pgoff                              0.0223
     29 get_unmapped_area                          0.1007
     34 find_vma                                   0.3542
      1 find_vma_prev                              0.0057
      1 unmap_fixup                                0.0030
      2 free_pgtables                              0.0114
      8 do_munmap                                  0.0125
      1 sys_munmap                                 0.0089
      3 exit_mmap                                  0.0099
     11 set_page_dirty                             0.0764
      1 add_to_page_cache_unique                   0.0069
      7 unlock_page                                0.0547
     76 __find_get_page                            1.5833
      3 __find_lock_page_helper                    0.0312
      7 generic_file_readahead                     0.0182
     12 mark_page_accessed                         0.2500
     25 do_generic_file_read                       0.0226
    124 file_read_actor                            0.7750
      1 generic_file_read                          0.0024
     44 filemap_nopage                             0.0833
      4 generic_file_mmap                          0.0357
      1 read_cache_page                            0.0063
     10 do_generic_file_write                      0.0098
      1 __read_cache_page                          0.0048
      1 kmalloc                                    0.0125
     20 kmem_cache_free                            0.4167
      1 kfree                                      0.0156
     20 __kmem_cache_alloc                         0.0833
     37 lru_cache_add                              0.3304
     11 __lru_cache_del                            0.0764
     22 delta_nr_inactive_pages                    0.2750
     52 __free_pages_ok                            0.0813
    152 rmqueue                                    0.2794
      6 _alloc_pages                               0.1875
     12 __alloc_pages                              0.0197
     13 __free_pages                               0.4062
      7 nr_free_pages                              0.0875
      4 free_page_and_swap_cache                   0.0625
      1 can_share_swap_page                        0.0089
      7 fd_install                                 0.1458
      1 filp_open                                  0.0089
      2 dentry_open                                0.0045
      7 get_unused_fd                              0.0190
      4 sys_open                                   0.0250
      3 filp_close                                 0.0234
      2 sys_close                                  0.0208
      4 sys_read                                   0.0132
      2 sys_write                                  0.0066
      7 get_empty_filp                             0.0243
     12 fput                                       0.0417
      3 fget                                       0.0625
      2 file_move                                  0.0417
      2 __constant_c_and_count_memset              0.0156
      1 __remove_from_lru_list                     0.0104
     15 get_hash_table                             0.1172
     11 getblk                                     0.1146
      1 balance_dirty_state                        0.0125
      1 __brelse                                   0.0312
      1 create_buffers                             0.0045
      4 __block_prepare_write                      0.0053
      1 block_read_full_page                       0.0016
      6 cp_new_stat64                              0.0208
      3 sys_stat64                                 0.0234
      6 sys_fstat64                                0.0469
      3 __constant_c_and_count_memset              0.0208
      1 __constant_copy_to_user                    0.0063
      5 copy_strings                               0.0098
      1 setup_arg_pages                            0.0031
      2 kernel_read                                0.0156
      1 exec_mmap                                  0.0028
      1 flush_old_exec                             0.0016
      1 prepare_binprm                             0.0031
      1 __constant_c_and_count_memset              0.0078
      1 pipe_read                                  0.0020
      3 getname                                    0.0144
      5 vfs_permission                             0.0184
      4 permission                                 0.0625
      2 cached_lookup                              0.0179
     27 link_path_walk                             0.0162
      1 path_lookup                                0.0156
      8 path_init                                  0.0714
      2 __user_walk                                0.0208
     14 open_namei                                 0.0105
      5 page_getlink                               0.0312
      2 page_follow_link                           0.0250
      1 walk_init_root                             0.0057
      1 __vfs_follow_link                          0.0049
      1 locks_remove_posix                         0.0028
      2 locks_remove_flock                         0.0179
     10 dput                                       0.0298
      1 d_alloc                                    0.0024
     64 d_lookup                                   0.2667
      1 alloc_inode                                0.0030
      1 __mark_inode_dirty                         0.0063
      2 iget4_locked                               0.0083
      1 insert_inode_hash                          0.0125
      1 update_atime                               0.0089
      2 dnotify_flush                              0.0139
      1 create_elf_tables                          0.0013
      3 load_elf_binary                            0.0009
      1 proc_lookup                                0.0048
      2 scan_bitmap_block                          0.0017
      1 scan_bitmap                                0.0018
      1 determine_search_start                     0.0011
      5 balance_leaf                               0.0004
      2 bin_search_in_dir_item                     0.0114
      2 search_by_entry_key                        0.0039
      1 linear_search_in_dir_item                  0.0014
      1 reiserfs_add_entry                         0.0008
      1 reiserfs_create                            0.0024
      1 __constant_c_and_count_memset              0.0057
      4 _make_cpu_key                              0.0192
      1 make_cpu_key                               0.0104
      2 reiserfs_get_block                         0.0004
      4 update_stat_data                           0.0139
      3 reiserfs_update_sd                         0.0067
      1 reiserfs_new_inode                         0.0007
      1 reiserfs_truncate_file                     0.0018
      1 reiserfs_prepare_write                     0.0078
      1 reiserfs_commit_write                      0.0027
      9 reiserfs_file_release                      0.0085
      2 create_virtual_node                        0.0015
      1 check_left                                 0.0031
      1 check_right                                0.0031
      3 get_num_ver                                0.0033
      1 set_parameters                             0.0069
      1 get_lfree                                  0.0089
      1 get_rfree                                  0.0089
      1 ip_check_balance                           0.0003
      1 get_direct_parent                          0.0048
      2 get_neighbors                              0.0063
      2 wait_tb_buffers_until_unlocked             0.0025
      2 reiserfs_dirty_inode                       0.0156
      1 reiserfs_release_objectid                  0.0024
      2 leaf_copy_items_entirely                   0.0030
      5 leaf_insert_into_buf                       0.0073
      7 leaf_paste_in_buffer                       0.0084
      1 leaf_cut_entries                           0.0033
      1 leaf_cut_from_buffer                       0.0009
      1 __constant_c_and_count_memset              0.0063
      1 internal_insert_childs                     0.0019
      1 __constant_memcpy                          0.0039
      1 decrement_counters_in_path                 0.0125
      4 is_leaf                                    0.0083
      5 is_tree_node                               0.0446
     29 search_by_key                              0.0084
      1 search_for_position_by_key                 0.0010
      1 comp_items                                 0.0104
      1 prepare_for_delete_or_cut                  0.0006
      1 calc_deleted_bytes_number                  0.0020
      1 init_tb_struct                             0.0104
      1 reiserfs_delete_solid_item                 0.0017
      1 maybe_indirect_to_direct                   0.0015
      1 reiserfs_cut_from_item                     0.0008
      1 B_IS_IN_TREE                               0.0312
      3 __constant_memcpy                          0.0117
      1 get_cnode                                  0.0069
      4 reiserfs_in_journal                        0.0076
      1 flush_commit_list                          0.0009
      7 kupdate_one_transaction                    0.0133
      5 do_journal_begin_r                         0.0082
      1 journal_mark_dirty                         0.0013
      2 can_dirty                                  0.0114
      2 check_journal_end                          0.0033
      1 reiserfs_restore_prepared_buffer           0.0312
      1 reiserfs_prepare_for_journal               0.0069
      1 __constant_c_and_count_memset              0.0069
      1 sd_create_vi                               0.0625
      1 indirect_part_size                         0.0625
      3 direntry_create_vi                         0.0078
      1 direntry_part_size                         0.0156
      1 release_dev                                0.0006
      1 add_entropy_words                          0.0063
      1 credit_entropy_store                       0.0208
      1 generic_unplug_device                      0.0156
      2 __make_request                             0.0011
      1 generic_make_request                       0.0033
     11 ide_inb                                    0.6875
     18 ide_outb                                   1.1250
      3 ide_outl                                   0.1875
      3 ide_execute_command                        0.0187
      1 ide_start_request                          0.0020
      1 ide_do_request                             0.0025
      1 ide_intr                                   0.0033
      5 ide_build_sglist                           0.0098
      1 __ide_do_rw_disk                           0.0006
      1 idedisk_end_request                        0.0048
      1 sock_poll                                  0.0156
      6 __rdtsc_delay                              0.1875
      6 __generic_copy_to_user                     0.0625
      5 __generic_copy_from_user                   0.0446
      8 strncpy_from_user                          0.0714
      5 clear_user                                 0.0625
     23 strnlen_user                               0.3026
     37 _mmx_memcpy                                0.1101
    824 fast_clear_page                           10.3000
    129 fast_copy_page                             0.5759
     10 mmx_clear_page                             0.3125
      5 number                                     0.0071
      1 vsnprintf                                  0.0009
      2 __rb_rotate_left                           0.0312
      2 rb_insert_color                            0.0083
      1 rb_erase                                   0.0035
   8729 total                                      0.0076


Kernel 2.6.4

  79186 default_idle                             1649,7083
      1 cpu_idle                                   0,0156
      2 exit_thread                                0,0312
      1 release_thread                             0,0104
      5 copy_thread                                0,0082
      1 sys_fork                                   0,0156
      1 sys_execve                                 0,0078
      4 restore_sigcontext                         0,0125
      2 sys_sigreturn                              0,0096
      4 setup_sigcontext                           0,0132
      8 setup_frame                                0,0161
      3 handle_signal                              0,0110
      3 do_signal                                  0,0104
      1 do_notify_resume                           0,0179
      1 ret_from_fork                              0,0500
     87 ret_from_intr                              3,1071
      4 resume_userspace                           0,1667
    243 system_call                                5,5227
      3 syscall_call                               0,2727
     19 syscall_exit                               1,7273
      3 restore_all                                0,2143
     34 error_code                                 0,6071
    161 device_not_available                       3,9268
      1 device_not_available_emulate               0,0667
     76 math_state_restore                         0,9500
      5 handle_IRQ_event                           0,0446
      3 release_x86_irqs                           0,0312
      9 init_new_context                           0,0312
      2 destroy_context                            0,0125
      1 sys_pipe                                   0,0069
      3 sys_mmap2                                  0,0134
    166 old_mmap                                   0,4323
      3 init_fpu                                   0,0208
    191 kernel_fpu_begin                           2,9844
     98 restore_fpu                                3,0625
      4 convert_fxsr_to_user                       0,0114
      1 convert_fxsr_from_user                     0,0042
      3 save_i387                                  0,0156
      1 restore_i387                               0,0078
      1 sched_clock                                0,0069
     49 delay_pmtmr                                1,5312
      2 pte_alloc_one                              0,0250
      1 pgd_alloc                                  0,0312
      1 pgd_free                                   0,0312
   2112 do_page_fault                              1,5976
      2 try_to_wake_up                             0,0063
      4 sched_fork                                 0,0312
      7 wake_up_forked_process                     0,0199
     15 schedule_tail                              0,0852
     62 schedule                                   0,0484
     57 __wake_up                                  1,1875
      1 complete                                   0,0156
      1 wait_for_completion                        0,0057
    363 __might_sleep                              2,2687
      1 free_task                                  0,0208
      3 __put_task_struct                          0,0117
      2 add_wait_queue                             0,0417
      2 remove_wait_queue                          0,0312
      2 prepare_to_wait                            0,0250
      1 finish_wait                                0,0125
     24 dup_task_struct                            0,1154
      4 mm_init                                    0,0179
      8 mm_alloc                                   0,1250
      2 __mmdrop                                   0,0250
      4 mmput                                      0,0357
      1 mm_release                                 0,0052
     67 copy_mm                                    0,0598
      4 count_open_files                           0,0833
     10 copy_files                                 0,0145
      3 unshare_files                              0,0312
     57 copy_process                               0,0239
      5 do_fork                                    0,0137
      1 release_console_sem                        0,0063
     42 release_task                               0,0972
      3 put_files_struct                           0,0156
     44 exit_notify                                0,0235
      8 do_exit                                    0,0091
      3 next_thread                                0,0938
      3 do_group_exit                              0,0234
      1 sys_exit_group                             0,0312
      2 eligible_child                             0,0083
      3 wait_task_zombie                           0,0072
      7 sys_wait4                                  0,0118
      2 sys_waitpid                                0,0465
     16 current_kernel_time                        0,2500
      2 get_jiffies_64                             0,0312
   3650 do_softirq                                22,8125
      3 tasklet_action                             0,0268
      1 parse_table                                0,0030
     22 __mod_timer                                0,1528
      2 mod_timer                                  0,0179
    171 run_timer_softirq                          0,4647
      1 sys_getpid                                 0,0625
      1 sys_getppid                                0,0312
      3 sys_getegid                                0,1875
      3 free_uid                                   0,0375
      7 flush_signal_handlers                      0,0875
     20 get_signal_to_deliver                      0,0266
     21 sigprocmask                                0,1094
     11 sys_rt_sigprocmask                         0,0286
     22 do_sigaction                               0,0529
      8 sys_rt_sigaction                           0,0250
    122 groups_search                              1,0893
     52 in_group_p                                 0,4062
      2 sys_newuname                               0,0114
      1 sys_getrlimit                              0,0069
      1 sys_umask                                  0,0312
      6 alloc_pidmap                               0,0129
      1 call_rcu                                   0,0208
      1 rcu_check_quiescent_state                  0,0104
      1 rcu_process_callbacks                      0,0045
      2 kthread_should_stop                        0,0625
      3 acct_process                               0,0517
      1 __remove_from_page_cache                   0,0089
      2 add_to_page_cache                          0,0096
     12 page_waitqueue                             0,2500
     23 unlock_page                                0,2396
    458 find_get_page                              9,5417
      6 find_lock_page                             0,0417
      2 find_or_create_page                        0,0104
      2 find_get_pages                             0,0250
     90 do_generic_mapping_read                    0,0953
     49 file_read_actor                            0,1914
     43 __generic_file_aio_read                    0,0896
     12 generic_file_read                          0,0682
    145 filemap_nopage                             0,1888
     19 generic_file_mmap                          0,2969
     17 read_cache_page                            0,0312
      3 remove_suid                                0,0268
     17 generic_file_aio_write_nolock              0,0067
      1 generic_file_write_nolock                  0,0063
      3 generic_file_write                         0,0208
      2 generic_write_checks                       0,0033
     13 mempool_alloc                              0,0451
      1 mempool_alloc_slab                         0,0312
    177 bad_range                                  1,5804
    135 prep_new_page                              1,4062
    605 free_hot_cold_page                         2,7009
      5 free_hot_page                              0,3125
   1549 buffered_rmqueue                           5,6949
    391 __alloc_pages                              0,4611
      1 __get_free_pages                           0,0125
      1 __free_pages                               0,0125
      1 free_pages                                 0,0156
     78 nr_free_pages                              0,9750
      2 get_zone_counts                            0,0156
      1 balance_dirty_pages_ratelimited            0,0156
      6 __set_page_dirty_nobuffers                 0,0417
      3 test_clear_page_dirty                      0,0375
     39 file_ra_state_init                         1,2188
     19 do_page_cache_readahead                    0,0699
     65 page_cache_readahead                       0,1562
    165 kmem_cache_alloc                           1,4732
     26 __kmalloc                                  0,1625
    114 kmem_cache_free                            1,4250
     17 kfree                                      0,1518
     11 reap_timer_fnc                             0,0286
      7 activate_page                              0,0547
    250 mark_page_accessed                         5,2083
      1 lru_cache_add                              0,0208
    100 lru_cache_add_active                       2,0833
     10 lru_add_drain                              0,1562
    104 __page_cache_release                       0,6500
     74 release_pages                              0,2721
      4 __pagevec_lru_add                          0,0250
    221 __pagevec_lru_add_active                   1,2557
      1 truncate_complete_page                     0,0078
      1 shrink_cache                               0,0016
      1 blk_queue_bounce                           0,0104
    101 clear_page_tables                          0,5739
    222 pte_alloc_map                              1,3875
    251 copy_page_range                            0,3826
    827 zap_pte_range                              2,1536
     14 zap_pmd_range                              0,1250
     12 unmap_page_range                           0,1071
     43 unmap_vmas                                 0,0814
     65 do_wp_page                                 0,0945
    624 do_anonymous_page                          1,5000
    619 do_no_page                                 0,8793
    577 handle_mm_fault                            1,8031
     40 remove_shared_vm_struct                    0,2778
     10 sys_brk                                    0,0347
    110 find_vma_prepare                           0,9821
      4 __vma_link_rb                              0,0625
     18 __vma_link                                 0,1125
     12 vma_link                                   0,0750
      2 __insert_vm_struct                         0,0139
      8 can_vma_merge_before                       0,1000
     14 can_vma_merge_after                        0,1750
     85 vma_merge                                  0,1207
    378 do_mmap_pgoff                              0,2128
     79 get_unmapped_area                          0,2469
    566 find_vma                                   5,8958
     28 find_vma_prev                              0,2917
      3 expand_stack                               0,0208
     10 free_pgtables                              0,0625
     10 unmap_vma                                  0,0781
      3 unmap_vma_list                             0,0625
     29 unmap_region                               0,1295
     28 detach_vmas_to_be_unmapped                 0,2500
     17 split_vma                                  0,0409
     32 do_munmap                                  0,0909
     16 sys_munmap                                 0,1250
     18 do_brk                                     0,0331
     17 exit_mmap                                  0,0443
      2 insert_vm_struct                           0,0156
      1 get_one_pte_map_nested                     0,0069
    494 page_add_rmap                              3,4306
    308 page_remove_rmap                           1,1324
    215 __pte_chain_free                           2,6875
     84 pte_chain_alloc                            0,8750
     66 free_page_and_swap_cache                   0,5893
      5 can_share_swap_page                        0,0446
      3 si_swapinfo                                0,0375
      1 sys_access                                 0,0030
     29 filp_open                                  0,2589
     89 dentry_open                                0,2139
     58 get_unused_fd                              0,1510
     25 fd_install                                 0,5208
     21 sys_open                                   0,1458
     29 filp_close                                 0,2014
     43 sys_close                                  0,4479
      2 default_llseek                             0,0156
      4 sys_llseek                                 0,0156
     69 vfs_read                                   0,2156
     15 vfs_write                                  0,0469
     17 sys_read                                   0,1518
      8 sys_write                                  0,0714
     42 get_empty_filp                             0,1641
     22 fput                                       0,6875
     52 __fput                                     0,2031
     34 fget                                       0,7083
     37 fget_light                                 0,3854
     20 file_move                                  0,4167
     15 file_kill                                  0,4688
     63 __constant_c_and_count_memset              0,4922
      3 __set_page_buffers                         0,0469
    170 __find_get_block_slow                      0,5592
      1 mark_buffer_async_write                    0,0312
      1 inode_has_buffers                          0,0312
     36 __set_page_dirty_buffers                   0,1607
      1 invalidate_inode_buffers                   0,0125
      1 create_buffers                             0,0057
      1 init_page_buffers                          0,0089
      1 grow_dev_page                              0,0033
      1 __getblk_slow                              0,0035
      3 mark_buffer_dirty                          0,0375
     65 __brelse                                   1,0156
     56 bh_lru_install                             0,2917
    408 __find_get_block                           1,8214
     39 __getblk                                   0,3482
     28 __bread                                    0,3500
      1 set_bh_page                                0,0156
      3 block_invalidatepage                       0,0125
      5 create_empty_buffers                       0,0391
      6 __block_write_full_page                    0,0060
     27 __block_prepare_write                      0,0241
      5 __block_commit_write                       0,0347
      3 block_read_full_page                       0,0041
      2 block_prepare_write                        0,0250
      2 block_commit_write                         0,0417
      1 generic_commit_write                       0,0069
     11 submit_bh                                  0,0229
      1 ll_rw_block                                0,0078
      4 drop_buffers                               0,0179
      3 alloc_buffer_head                          0,0469
      1 free_buffer_head                           0,0156
      9 bio_alloc                                  0,0216
      1 bio_clone                                  0,0063
      3 sync_supers                                0,0170
      2 blkdev_writepage                           0,0417
     12 nr_blockdev_pages                          0,1875
      3 chrdev_open                                0,0094
      1 cdev_get                                   0,0104
     38 generic_fillattr                           0,2969
     52 vfs_getattr                                0,2708
      2 vfs_stat                                   0,0208
     14 vfs_fstat                                  0,1750
     59 cp_new_stat64                              0,1844
      1 sys_stat64                                 0,0156
     25 sys_fstat64                                0,3906
      7 count                                      0,1094
    101 copy_strings                               0,1661
      2 copy_strings_kernel                        0,0250
      8 put_dirty_page                             0,0312
      8 setup_arg_pages                            0,0179
      7 open_exec                                  0,0292
      1 kernel_read                                0,0104
      2 exec_mmap                                  0,0078
     27 flush_old_exec                             0,0147
      3 prepare_binprm                             0,0144
      4 compute_creds                              0,0156
      9 search_binary_handler                      0,0201
      6 do_execve                                  0,0096
      3 set_binfmt                                 0,0312
      3 pipe_wait                                  0,0156
      7 pipe_readv                                 0,0091
      1 pipe_read                                  0,0156
     15 pipe_writev                                0,0162
      1 pipe_write                                 0,0156
      1 pipe_read_release                          0,0156
      1 pipe_new                                   0,0048
      2 get_pipe_inode                             0,0104
      1 do_pipe                                    0,0019
     46 getname                                    0,2212
     30 vfs_permission                             0,1042
     14 permission                                 0,1094
      3 deny_write_access                          0,0625
      4 path_release                               0,0625
      2 cached_lookup                              0,0139
      1 real_lookup                                0,0037
     56 follow_mount                               0,3889
     48 do_lookup                                  0,2727
    528 link_path_walk                             0,2519
     75 path_lookup                                0,2757
      5 __lookup_hash                              0,0223
      2 lookup_hash                                0,0417
      6 __user_walk                                0,0625
      5 vfs_create                                 0,0184
    122 may_open                                   0,2824
     27 open_namei                                 0,0241
      1 vfs_unlink                                 0,0023
      1 sys_unlink                                 0,0030
      1 vfs_rename_other                           0,0031
      2 vfs_rename                                 0,0025
      1 sys_rename                                 0,0018
     23 page_getlink                               0,1106
     35 page_follow_link                           0,0841
      1 expand_files                               0,0089
      1 locate_fd                                  0,0035
      1 dupfd                                      0,0089
      1 sys_dup                                    0,0156
      1 kill_fasync                                0,0156
      3 sys_ioctl                                  0,0048
      1 filldir64                                  0,0031
      1 sys_getdents64                             0,0059
      1 poll_freewait                              0,0125
      1 __pollwait                                 0,0048
      3 do_select                                  0,0044
      3 sys_select                                 0,0023
     33 locks_remove_posix                         0,1719
     18 locks_remove_flock                         0,1607
      1 steal_locks                                0,0104
     80 dput                                       0,2273
      5 d_alloc                                    0,0104
      7 d_instantiate                              0,0729
      2 d_lookup                                   0,0250
    620 __d_lookup                                 2,4219
      1 d_rehash                                   0,0125
      1 sys_getcwd                                 0,0021
      7 alloc_inode                                0,0175
      3 destroy_inode                              0,0312
      2 inode_init_once                            0,0069
      1 __iget                                     0,0104
      1 clear_inode                                0,0057
      1 prune_icache                               0,0022
      4 find_inode_fast                            0,0417
      1 get_new_inode_fast                         0,0052
      2 iget_locked                                0,0125
      2 __insert_inode_hash                        0,0312
      1 generic_delete_inode                       0,0045
      2 generic_forget_inode                       0,0074
      1 generic_drop_inode                         0,0312
     25 inode_times_differ                         0,3125
     55 update_atime                               0,2455
      1 inode_update_time                          0,0048
      1 i_waitq_head                               0,0312
      2 is_bad_inode                               0,0625
     15 dnotify_flush                              0,1042
     64 dnotify_parent                             0,5000
      7 lookup_mnt                                 0,0729
      3 copy_namespace                             0,0042
     51 __mark_inode_dirty                         0,2452
      6 __sync_single_inode                        0,0125
      1 __writeback_single_inode                   0,0057
      4 sync_sb_inodes                             0,0071
      3 writeback_inodes                           0,0375
      2 writeback_acquire                          0,0625
     24 do_mpage_readpage                          0,0211
      6 mpage_writepages                           0,0087
      6 exit_aio                                   0,0417
      6 eventpoll_init_file                        0,3750
      2 eventpoll_release_file                     0,0096
      1 padzero                                    0,0208
     16 create_elf_tables                          0,0172
      7 elf_map                                    0,0312
      8 load_elf_interp                            0,0139
     33 load_elf_binary                            0,0104
      1 proc_delete_inode                          0,0089
      1 proc_read_inode                            0,0156
      1 proc_destroy_inode                         0,0312
      1 proc_get_inode                             0,0042
      1 proc_pid_unhash                            0,0104
      5 proc_pid_flush                             0,1042
      2 proc_file_read                             0,0030
     16 proc_lookup                                0,0833
     49 get_vmalloc_info                           0,3828
      3 meminfo_read_proc                          0,0060
      2 write_profile                              0,0312
     20 scan_bitmap_block                          0,0171
      1 scan_bitmap                                0,0018
      4 _reiserfs_free_block                       0,0119
      1 reiserfs_free_block                        0,0156
      1 reiserfs_discard_all_prealloc              0,0156
      2 determine_prealloc_size                    0,0139
     11 reiserfs_allocate_blocknrs                 0,0056
      2 balance_leaf_when_delete                   0,0018
     19 balance_leaf                               0,0016
      1 free_thrown                                0,0089
      1 get_left_neighbor_position                 0,0208
      5 do_balance                                 0,0184
      4 do_balance_mark_leaf_dirty                 0,0278
      6 bin_search_in_dir_item                     0,0341
      6 search_by_entry_key                        0,0121
      5 get_third_component                        0,0521
      1 reiserfs_match                             0,0089
      5 linear_search_in_dir_item                  0,0069
      3 reiserfs_find_entry                        0,0085
      2 reiserfs_lookup                            0,0066
      8 reiserfs_add_entry                         0,0066
      1 new_inode_init                             0,0089
      2 reiserfs_create                            0,0048
      1 reiserfs_mkdir                             0,0015
      2 reiserfs_unlink                            0,0030
      1 entry_points_to_object                     0,0063
      3 reiserfs_rename                            0,0012
     33 _make_cpu_key                              0,1587
     70 make_cpu_key                               0,6250
      1 file_capable                               0,0156
      2 _get_block_create_0                        0,0011
     13 reiserfs_get_block                         0,0026
     70 inode2sd                                   0,3646
      7 inode2sd_v1                                0,0486
     38 update_stat_data                           0,1397
     62 reiserfs_update_sd                         0,1435
     14 reiserfs_new_inode                         0,0097
      2 grab_tail_page                             0,0050
      3 reiserfs_truncate_file                     0,0059
      1 lock_buffer_for_writepage                  0,0063
     20 reiserfs_write_full_page                   0,0250
      3 reiserfs_prepare_write                     0,0187
      5 reiserfs_commit_write                      0,0136
     24 i_attrs_to_sd_attrs                        0,2143
      1 reiserfs_releasepage                       0,0089
      1 make_le_item_head                          0,0045
     66 reiserfs_file_release                      0,0607
      5 reiserfs_allocate_blocks_for_region        0,0010
      2 reiserfs_copy_from_user_to_file_region     0,0078
      2 reiserfs_check_for_tail_and_convert        0,0048
     15 reiserfs_prepare_file_region_for_write     0,0063
      3 reiserfs_file_write                        0,0018
      3 reiserfs_readdir                           0,0023
     12 create_virtual_node                        0,0094
      4 check_left                                 0,0125
      2 check_right                                0,0063
     12 get_num_ver                                0,0139
      4 set_parameters                             0,0278
      2 is_leaf_removable                          0,0066
      2 get_empty_nodes                            0,0039
      5 get_lfree                                  0,0446
      2 get_rfree                                  0,0179
      1 get_far_parent                             0,0014
      7 get_parents                                0,0168
     11 ip_check_balance                           0,0038
      1 dc_check_balance_leaf                      0,0018
      1 dc_check_balance                           0,0208
      5 check_balance                              0,0284
      3 get_direct_parent                          0,0110
      2 get_neighbors                              0,0057
      5 get_virtual_node_size                      0,0625
      5 get_mem_for_virtual_node                   0,0208
     11 wait_tb_buffers_until_unlocked             0,0135
     14 fix_nodes                                  0,0139
      5 unfix_nodes                                0,0130
      1 is_reiserfs_jr                             0,0125
      1 init_once                                  0,0208
     28 reiserfs_dirty_inode                       0,2188
      4 reiserfs_get_unused_objectid               0,0139
      2 leaf_copy_boundary_item                    0,0011
      1 leaf_copy_items_entirely                   0,0013
      1 leaf_copy_items                            0,0025
      3 leaf_define_dest_src_infos                 0,0069
      3 leaf_move_items                            0,0187
      2 leaf_delete_items                          0,0045
     23 leaf_insert_into_buf                       0,0271
      9 leaf_paste_in_buffer                       0,0097
      3 leaf_cut_entries                           0,0072
      8 leaf_cut_from_buffer                       0,0065
     16 leaf_delete_items_entirely                 0,0278
     10 leaf_paste_entries                         0,0133
      8 internal_insert_childs                     0,0128
      1 internal_delete_pointers_items             0,0021
      1 balance_internal_when_delete               0,0017
      1 balance_internal                           0,0004
     19 decrement_counters_in_path                 0,2375
      1 pathrelse_and_restore                      0,0125
     25 pathrelse                                  0,3906
    301 is_leaf                                    0,6487
     53 is_internal                                0,3312
    164 is_tree_node                               1,4643
    729 search_by_key                              0,1906
     13 search_for_position_by_key                 0,0133
      3 comp_items                                 0,0268
     10 prepare_for_delete_or_cut                  0,0053
      1 calc_deleted_bytes_number                  0,0021
      4 init_tb_struct                             0,0417
      1 reiserfs_delete_solid_item                 0,0018
      2 maybe_indirect_to_direct                   0,0030
      5 reiserfs_cut_from_item                     0,0040
      6 reiserfs_do_truncate                       0,0045
      2 reiserfs_paste_into_item                   0,0066
      6 reiserfs_insert_item                       0,0187
      2 B_IS_IN_TREE                               0,0625
     18 copy_item_head                             0,3750
      5 decrement_bcount                           0,0781
      1 keyed_hash                                 0,0010
      2 r5_hash                                    0,0250
      1 unmap_buffers                              0,0069
      4 indirect2direct                            0,0054
     20 init_journal_hash                          0,6250
      4 get_bitmap_node                            0,0250
      1 set_bit_in_list_bitmap                     0,0089
      1 cleanup_bitmap_list                        0,0048
     10 get_cnode                                  0,0694
      3 free_cnode                                 0,0208
      1 clear_prepared_bits                        0,0625
      1 reiserfs_check_lock_depth                  0,0625
      1 push_journal_writer                        0,0625
      1 pop_journal_writer                         0,0625
     20 reiserfs_in_journal                        0,0417
      7 flush_commit_list                          0,0061
      2 find_newer_jl_for_cn                       0,0417
      1 submit_logged_buffer                       0,0104
      1 flush_journal_list                         0,0010
     68 kupdate_one_transaction                    0,1288
      1 reiserfs_journal_kupdate                   0,0057
     37 remove_journal_hash                        0,1927
      8 reiserfs_wait_on_write_block               0,0556
    206 do_journal_begin_r                         0,3065
     23 journal_begin                              0,4792
     62 journal_mark_dirty                         0,0861
     13 journal_end                                0,2708
      3 remove_from_transaction                    0,0082
     34 can_dirty                                  0,1932
      1 flush_old_commits                          0,0022
     81 check_journal_end                          0,1235
      2 journal_mark_freed                         0,0036
      3 reiserfs_update_inode_transaction          0,0469
      8 reiserfs_restore_prepared_buffer           0,2500
     39 reiserfs_prepare_for_journal               0,3482
     98 do_journal_end                             0,0302
      1 mark_buffer_journal_new                    0,0625
      2 sd_bytes_number                            0,1250
      1 sd_is_left_mergeable                       0,0625
      1 sd_create_vi                               0,0625
      5 sd_part_size                               0,1562
      5 direct_is_left_mergeable                   0,0347
      2 direct_create_vi                           0,1250
      3 direct_part_size                           0,1875
      1 indirect_bytes_number                      0,0312
      1 indirect_create_vi                         0,0625
      2 indirect_part_size                         0,1250
      1 direntry_is_left_mergeable                 0,0625
      1 direntry_print_item                        0,0024
     13 direntry_create_vi                         0,0325
      1 direntry_check_left                        0,0069
      4 direntry_part_size                         0,0625
      3 copy_semundo                               0,0144
      2 exit_sem                                   0,0060
      1 capable                                    0,0104
     84 dummy_vm_enough_memory                     0,4773
      6 dummy_bprm_secureexec                      0,0938
      6 dummy_inode_alloc_security                 0,3750
      2 dummy_inode_create                         0,1250
      2 dummy_inode_follow_link                    0,1250
     30 dummy_inode_permission                     1,8750
      6 dummy_file_permission                      0,3750
     11 dummy_file_alloc_security                  0,6875
      5 dummy_file_free_security                   0,3125
     34 dummy_file_mmap                            2,1250
      1 dummy_task_wait                            0,0625
      1 dummy_d_instantiate                        0,0625
      2 radix_tree_preload                         0,0156
      2 radix_tree_insert                          0,0104
    443 radix_tree_lookup                          5,5375
      1 radix_tree_delete                          0,0042
      6 __rb_rotate_left                           0,0938
      2 __rb_rotate_right                          0,0312
     33 rb_insert_color                            0,1375
      7 __rb_erase_color                           0,0162
     18 rb_erase                                   0,0703
     32 number                                     0,0435
     14 vsnprintf                                  0,0118
      1 vsprintf                                   0,0208
      1 __delay                                    0,0312
      1 __const_udelay                             0,0278
      4 __get_user_4                               0,1739
      4 bad_get_user                               0,1600
     34 memcpy                                     0,3542
    382 _mmx_memcpy                                1,0852
   8292 fast_clear_page                          103,6500
    900 fast_copy_page                             4,0179
     69 mmx_clear_page                             2,1562
      1 mmx_copy_page                              0,0208
     89 strncpy_from_user                          0,7946
     65 clear_user                                 0,6771
    150 strnlen_user                               1,5625
      1 __copy_user_intel                          0,0057
   2431 __copy_to_user_ll                         21,7054
    256 __copy_from_user_ll                        2,2857
      2 init_dev                                   0,0014
      2 release_dev                                0,0014
      1 tty_ioctl                                  0,0007
      1 n_tty_ioctl                                0,0009
      3 vt_ioctl                                   0,0004
      1 vc_allocate                                0,0022
      4 con_open                                   0,0227
     15 blk_rq_map_sg                              0,0446
     11 generic_unplug_device                      0,1146
      1 blk_run_queues                             0,0078
      1 ioc_set_batching                           0,0156
      7 get_request                                0,0125
      1 get_request_wait                           0,0045
     81 __make_request                             0,0582
      5 generic_make_request                       0,0101
      1 submit_bio                                 0,0089
      5 as_set_request                             0,0347
    131 ide_end_request                            0,4309
      7 start_request                              0,0107
     75 ide_do_request                             0,0901
     27 ide_intr                                   0,0844
    111 ide_inb                                    6,9375
    268 ide_outb                                  16,7500
     12 ide_outl                                   0,7500
      2 SELECT_DRIVE                               0,0250
      2 ide_wait_stat                              0,0066
     26 ide_execute_command                        0,1806
      5 ide_dma_intr                               0,0260
      3 ide_build_sglist                           0,0170
      5 ide_build_dmatable                         0,0125
      1 ide_destroy_dmatable                       0,0208
      1 ide_start_dma                              0,0057
      3 __ide_dma_write                            0,0134
      6 __ide_dma_end                              0,0375
      6 __ide_do_rw_disk                           0,0033
      2 ide_do_rw_disk                             0,0208
     23 i8042_interrupt                            0,0757
      4 i8042_timer_func                           0,0833
      1 sock_poll                                  0,0156
120290 total                                      0,0752


Hope that helps,
regards,
Andreas

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
  2004-03-29 14:23     ` Chris Mason
@ 2004-03-29 19:35       ` Andreas Hartmann
  2004-03-29 19:42       ` Andreas Hartmann
  2004-04-02  8:19       ` Andreas Hartmann
  2 siblings, 0 replies; 15+ messages in thread
From: Andreas Hartmann @ 2004-03-29 19:35 UTC (permalink / raw)
  To: Chris Mason; +Cc: Andrew Morton, linux-kernel

Chris Mason wrote:
> On Mon, 2004-03-29 at 01:16, Andreas Hartmann wrote:
>> Andrew Morton wrote:
>> > Andreas Hartmann <andihartmann@freenet.de> wrote:
>> >>
>> >> I tested kernel 2.6.4. While compiling kdelibs and kdebase, I felt, that
>> >>  kernel 2.6 seems to be slower than 2.4.25.
>> >> 
>> >>  So I did some tests to compare the performance directly. Therefore I
>> >>  rebooted for everey test in init 2 (no X).
>> >> 
>> >>  I locally compiled 2.6.5rc2 3 times under 2.6.4 and under 2.4.25 on a
>> >>  reiserfs LVM partition, which resides onto a IDE HD (using DMA) and got
>> >>  the following result:
>> >> 
>> >>  In the middle, compiling under kernel 2.6.4 tooks 9.3% more real time than
>> >>  under 2.4.25.
>> >>  The user-processortime is about the same, but the system-processortime is
>> >>  under 2.6.4 32.9% higher than under 2.4.25.
>> > 
>> > Try mounting your reiserfs filesystems with the `-o nolargeio=1' option.
>> 
>> This didn't help.
>> 
>> > 
>> > If that doesn't help, please run a comparative kernel profile.  See
>> > Documentation/basic_profiling.txt.
>> 
>> I'll do this next.
> 
> You might also want to try 2.6.5-rc2 which has a set of reiserfs fixes
> from 2.4.x.  I'm hoping those will clean things up for you.

Ok, here is the result for 2.6.5-rc2 (3 times middle, with preemption), 
compared to 2.4.25.

The result is, the performancedifference to 2.4.25 is the same as for 
2.6.4 as described above.
Nearly means: The real processing time is about 1% faster than under 
2.6.4, but 8.3% slower than with 2.4.25. The system-processortime is 1.2% 
faster than under 2.6.4 but 31,7% more than under 2.4.25. The times for 
the user-processortime is unchanged.

But I'm not shure if these values are really significant, because the 
values for the real time meassured each try differ a lot under 2.6.

For example 2.6.5rc2:
between 9.07 min and 8.37 min for real time.
Under 2.4.25, the differences are a lot of smaller: between 8.06 min and 
8.15 min for real time.
The values for user and system time are nearly constant with 6.49 min and 
36 sec (kernel 2.6) and 6.43 min / 27 sec for 2.4.25.


Regards,
Andreas Hartmann

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
  2004-03-29 14:23     ` Chris Mason
  2004-03-29 19:35       ` Andreas Hartmann
@ 2004-03-29 19:42       ` Andreas Hartmann
  2004-04-02  8:19       ` Andreas Hartmann
  2 siblings, 0 replies; 15+ messages in thread
From: Andreas Hartmann @ 2004-03-29 19:42 UTC (permalink / raw)
  To: Chris Mason; +Cc: Andrew Morton, linux-kernel

Chris Mason wrote:
> On Mon, 2004-03-29 at 01:16, Andreas Hartmann wrote:
>> Andrew Morton wrote:
>> > Andreas Hartmann <andihartmann@freenet.de> wrote:
>> >>
>> >> I tested kernel 2.6.4. While compiling kdelibs and kdebase, I felt, that
>> >>  kernel 2.6 seems to be slower than 2.4.25.
>> >> 
>> >>  So I did some tests to compare the performance directly. Therefore I
>> >>  rebooted for everey test in init 2 (no X).
>> >> 
>> >>  I locally compiled 2.6.5rc2 3 times under 2.6.4 and under 2.4.25 on a
>> >>  reiserfs LVM partition, which resides onto a IDE HD (using DMA) and got
>> >>  the following result:
>> >> 
>> >>  In the middle, compiling under kernel 2.6.4 tooks 9.3% more real time than
>> >>  under 2.4.25.
>> >>  The user-processortime is about the same, but the system-processortime is
>> >>  under 2.6.4 32.9% higher than under 2.4.25.
>> > 
>> > Try mounting your reiserfs filesystems with the `-o nolargeio=1' option.
>> 
>> This didn't help.
>> 
>> > 
>> > If that doesn't help, please run a comparative kernel profile.  See
>> > Documentation/basic_profiling.txt.
>> 
>> I'll do this next.
> 
> You might also want to try 2.6.5-rc2 which has a set of reiserfs fixes
> from 2.4.x.  I'm hoping those will clean things up for you.

Ooops, I forgot the profiling values for 2.6.5-rc2. Here they are (I took 
the values for the slowest run):


  99300 default_idle                             2068.7500
      2 exit_thread                                0.0312
      1 flush_thread                               0.0078
      3 prepare_to_copy                            0.0234
      2 copy_thread                                0.0033
      2 sys_fork                                   0.0312
      1 sys_vfork                                  0.0156
      1 sys_execve                                 0.0078
      3 restore_sigcontext                         0.0094
      1 sys_sigreturn                              0.0045
      3 setup_sigcontext                           0.0099
      5 setup_frame                                0.0101
      1 handle_signal                              0.0033
      1 do_signal                                  0.0035
    252 system_call                                5.7273
     12 syscall_exit                               1.0909
     31 error_code                                 0.5536
    184 device_not_available                       4.3810
     16 handle_IRQ_event                           0.1429
      3 release_x86_irqs                           0.0234
      1 init_new_context                           0.0037
      5 destroy_context                            0.0260
    127 old_mmap                                   0.3307
    218 kernel_fpu_begin                           3.4062
      1 convert_fxsr_to_user                       0.0028
      1 convert_fxsr_from_user                     0.0042
      3 save_i387                                  0.0110
      1 restore_i387_fxsave                        0.0069
      1 restore_i387                               0.0063
      2 sched_clock                                0.0139
     45 delay_pmtmr                                1.4062
      2 pte_alloc_one                              0.0250
      1 pgd_alloc                                  0.0312
      2 pgd_free                                   0.0625
   2170 do_page_fault                              1.6194
      3 sched_fork                                 0.0187
      3 wake_up_forked_process                     0.0078
     19 schedule_tail                              0.0913
     84 schedule                                   0.0590
      5 preempt_schedule                           0.0625
     74 __wake_up                                  0.7708
      1 wait_for_completion                        0.0045
      1 io_schedule                                0.0312
    525 __might_sleep                              2.5240
      1 free_task                                  0.0208
      2 __put_task_struct                          0.0078
      2 add_wait_queue                             0.0208
      5 remove_wait_queue                          0.0446
      4 prepare_to_wait                            0.0312
     24 dup_task_struct                            0.1154
      2 mm_init                                    0.0089
     11 mm_alloc                                   0.1719
      2 __mmdrop                                   0.0250
      6 mmput                                      0.0417
      4 mm_release                                 0.0208
     67 copy_mm                                    0.0574
      9 count_open_files                           0.1875
     13 copy_files                                 0.0153
      5 unshare_files                              0.0521
     55 copy_process                               0.0196
      3 do_fork                                    0.0082
     35 release_task                               0.0706
      3 put_files_struct                           0.0156
     45 exit_notify                                0.0232
     11 do_exit                                    0.0101
      4 do_group_exit                              0.0227
      3 sys_exit_group                             0.0938
      7 eligible_child                             0.0292
      4 wait_task_zombie                           0.0078
      6 sys_wait4                                  0.0099
      2 sys_waitpid                                0.0465
      1 .text.lock.exit                            0.0044
     20 current_kernel_time                        0.3125
      2 get_jiffies_64                             0.0312
   4190 do_softirq                                26.1875
      7 tasklet_action                             0.0625
     27 __mod_timer                                0.0734
      4 mod_timer                                  0.0357
      5 del_timer                                  0.0347
    178 run_timer_softirq                          0.4120
      1 sys_getpid                                 0.0625
      1 schedule_timeout                           0.0052
      5 flush_signal_handlers                      0.0625
      1 send_group_sig_info                        0.0104
     10 get_signal_to_deliver                      0.0118
     35 sigprocmask                                0.1823
     12 sys_rt_sigprocmask                         0.0300
     14 do_sigaction                               0.0273
      5 sys_rt_sigaction                           0.0149
    127 groups_search                              1.1339
     61 in_group_p                                 0.4766
      4 sys_newuname                               0.0227
      3 sys_getrlimit                              0.0208
      6 alloc_pidmap                               0.0121
      2 call_rcu                                   0.0417
      3 rcu_start_batch                            0.0469
      7 rcu_check_quiescent_state                  0.0486
      1 rcu_process_callbacks                      0.0039
      6 exit_itimers                               0.0469
      4 acct_process                               0.0286
      1 __remove_from_page_cache                   0.0089
      1 remove_from_page_cache                     0.0125
      1 add_to_page_cache                          0.0042
      2 add_to_page_cache_lru                      0.0250
     12 page_waitqueue                             0.2500
     33 unlock_page                                0.3438
      1 end_page_writeback                         0.0078
    452 find_get_page                              4.7083
      1 find_lock_page                             0.0048
      2 find_or_create_page                        0.0114
      1 find_get_pages                             0.0089
    102 do_generic_mapping_read                    0.1045
     46 file_read_actor                            0.1797
     46 __generic_file_aio_read                    0.0846
     17 generic_file_read                          0.0966
    180 filemap_nopage                             0.2123
     29 generic_file_mmap                          0.4531
     18 read_cache_page                            0.0331
     11 generic_file_aio_write_nolock              0.0040
      4 generic_file_write_nolock                  0.0250
      2 generic_file_write                         0.0139
      1 generic_write_checks                       0.0015
     20 mempool_alloc                              0.0543
      1 mempool_alloc_slab                         0.0312
    189 bad_range                                  1.6875
    152 prep_new_page                              1.5833
    577 free_hot_cold_page                         2.2539
      2 free_hot_page                              0.1250
   1676 buffered_rmqueue                           3.7411
    318 __alloc_pages                              0.3750
      1 free_pages                                 0.0156
    111 nr_free_pages                              1.3875
      1 get_page_state                             0.0312
      2 get_zone_counts                            0.0156
      1 get_dirty_limits                           0.0048
      4 balance_dirty_pages_ratelimited            0.0250
      1 do_writepages                              0.0156
      4 __set_page_dirty_nobuffers                 0.0179
      3 test_clear_page_dirty                      0.0312
     52 file_ra_state_init                         1.0833
     33 do_page_cache_readahead                    0.0897
     51 page_cache_readahead                       0.0996
      2 cache_grow                                 0.0031
    161 kmem_cache_alloc                           1.4375
      2 kmem_ptr_validate                          0.0250
     26 __kmalloc                                  0.1625
     94 kmem_cache_free                            1.1750
     17 kfree                                      0.1518
     12 reap_timer_fnc                             0.0242
      6 activate_page                              0.0375
    216 mark_page_accessed                         4.5000
    169 lru_cache_add_active                       1.7604
     13 lru_add_drain                              0.1354
    145 __page_cache_release                       1.0069
     91 release_pages                              0.2473
      5 __pagevec_lru_add                          0.0195
    227 __pagevec_lru_add_active                   0.8346
      1 shrink_list                                0.0008
      1 refill_inactive_zone                       0.0008
      3 blk_queue_bounce                           0.0312
     79 clear_page_tables                          0.4489
    286 pte_alloc_map                              1.4896
    238 copy_page_range                            0.2755
    744 zap_pte_range                              1.9375
      8 zap_pmd_range                              0.0714
     26 unmap_page_range                           0.2321
     46 unmap_vmas                                 0.0846
     48 do_wp_page                                 0.0577
    706 do_anonymous_page                          1.3789
    695 do_no_page                                 0.8865
    560 handle_mm_fault                            1.5217
     42 remove_shared_vm_struct                    0.2917
     12 sys_brk                                    0.0417
     78 find_vma_prepare                           0.6964
      6 __vma_link_rb                              0.0938
     21 __vma_link                                 0.1313
     23 vma_link                                   0.1437
      3 __insert_vm_struct                         0.0208
     12 can_vma_merge_before                       0.1500
     29 can_vma_merge_after                        0.3625
    113 vma_merge                                  0.1471
    418 do_mmap_pgoff                              0.2354
     81 get_unmapped_area                          0.2531
    500 find_vma                                   5.2083
     36 find_vma_prev                              0.3750
      2 expand_stack                               0.0104
     14 free_pgtables                              0.0875
     11 unmap_vma                                  0.0859
      6 unmap_vma_list                             0.1250
     18 unmap_region                               0.0804
     27 detach_vmas_to_be_unmapped                 0.2411
     16 split_vma                                  0.0357
     25 do_munmap                                  0.0625
     11 sys_munmap                                 0.0859
     11 do_brk                                     0.0202
     14 exit_mmap                                  0.0350
      3 insert_vm_struct                           0.0234
      1 get_one_pte_map_nested                     0.0069
    561 page_add_rmap                              3.1875
    426 page_remove_rmap                           1.4013
      1 try_to_unmap_one                           0.0024
    246 __pte_chain_free                           2.1964
    113 pte_chain_alloc                            0.5885
     69 free_page_and_swap_cache                   0.6161
      4 can_share_swap_page                        0.0357
      2 si_swapinfo                                0.0179
      2 sys_access                                 0.0060
      1 sys_chmod                                  0.0039
     35 filp_open                                  0.3125
    105 dentry_open                                0.1989
     76 get_unused_fd                              0.1827
      4 put_unused_fd                              0.0625
     30 fd_install                                 0.4688
     34 sys_open                                   0.2361
     31 filp_close                                 0.2153
     31 sys_close                                  0.1938
      5 default_llseek                             0.0208
      4 sys_llseek                                 0.0156
     60 vfs_read                                   0.1875
     16 vfs_write                                  0.0500
     14 sys_read                                   0.1250
      6 sys_write                                  0.0536
     54 get_empty_filp                             0.2109
     14 fput                                       0.4375
     56 __fput                                     0.1842
     29 fget                                       0.4531
     38 fget_light                                 0.2639
     43 file_move                                  0.4479
     28 file_kill                                  0.4375
     67 __constant_c_and_count_memset              0.4653
      1 __set_page_buffers                         0.0156
      1 __clear_page_buffers                       0.0156
    146 __find_get_block_slow                      0.4148
      1 mark_buffer_async_write                    0.0312
      1 inode_has_buffers                          0.0312
     65 __set_page_dirty_buffers                   0.2138
      3 create_buffers                             0.0170
      2 grow_dev_page                              0.0057
      2 __getblk_slow                              0.0069
      2 mark_buffer_dirty                          0.0250
     71 __brelse                                   1.1094
      2 __bforget                                  0.0208
     84 bh_lru_install                             0.3750
    457 __find_get_block                           1.7852
     46 __getblk                                   0.4107
     37 __bread                                    0.4625
      1 set_bh_page                                0.0156
      1 block_invalidatepage                       0.0042
      1 create_empty_buffers                       0.0063
      7 __block_write_full_page                    0.0067
     30 __block_prepare_write                      0.0268
      4 __block_commit_write                       0.0278
      1 block_read_full_page                       0.0013
      2 block_prepare_write                        0.0250
     11 submit_bh                                  0.0229
      2 check_ttfb_buffer                          0.0208
      2 free_buffer_head                           0.0179
      3 init_buffer_head                           0.0625
     19 bio_alloc                                  0.0457
      2 sync_supers                                0.0083
     17 nr_blockdev_pages                          0.1771
      2 chrdev_open                                0.0038
      1 cdev_get                                   0.0052
     30 generic_fillattr                           0.1875
     35 vfs_getattr                                0.1823
      6 vfs_stat                                   0.0625
     11 vfs_fstat                                  0.1375
     53 cp_new_stat64                              0.1656
      3 sys_stat64                                 0.0469
     26 sys_fstat64                                0.4062
      8 count                                      0.1250
    105 copy_strings                               0.1727
      3 put_dirty_page                             0.0089
     10 setup_arg_pages                            0.0223
      6 open_exec                                  0.0250
      1 kernel_read                                0.0104
      6 exec_mmap                                  0.0187
     13 flush_old_exec                             0.0060
      3 prepare_binprm                             0.0144
      3 compute_creds                              0.0104
     12 search_binary_handler                      0.0170
      4 do_execve                                  0.0064
      5 set_binfmt                                 0.0312
      7 pipe_wait                                  0.0365
     13 pipe_readv                                 0.0169
      7 pipe_writev                                0.0075
      2 pipe_write                                 0.0312
      2 pipe_release                               0.0089
      1 pipe_read_fasync                           0.0069
     27 getname                                    0.1298
     23 vfs_permission                             0.0799
     20 permission                                 0.1562
      3 deny_write_access                          0.0375
      1 path_release                               0.0156
      2 cached_lookup                              0.0139
      4 real_lookup                                0.0147
     39 follow_mount                               0.2708
     43 do_lookup                                  0.2443
    534 link_path_walk                             0.2181
     72 path_lookup                                0.2250
      1 __lookup_hash                              0.0045
      1 lookup_hash                                0.0208
      6 __user_walk                                0.0625
      1 lock_rename                                0.0028
      3 unlock_rename                              0.0375
      2 vfs_create                                 0.0074
    104 may_open                                   0.2407
     49 open_namei                                 0.0437
      1 vfs_unlink                                 0.0023
      1 sys_unlink                                 0.0030
      1 vfs_rename                                 0.0012
     26 page_getlink                               0.1250
     23 page_follow_link                           0.0479
      3 locate_fd                                  0.0104
      1 sys_dup2                                   0.0033
      2 do_fcntl                                   0.0046
      1 sys_fcntl64                                0.0052
      2 kill_fasync                                0.0156
      6 sys_ioctl                                  0.0083
      1 vfs_readdir                                0.0048
      1 filldir64                                  0.0031
      1 poll_freewait                              0.0125
      1 sys_select                                 0.0008
     31 locks_remove_posix                         0.1140
     34 locks_remove_flock                         0.1771
      3 steal_locks                                0.0144
      3 d_callback                                 0.0469
      2 d_free                                     0.0312
     63 dput                                       0.1193
      1 prune_dcache                               0.0022
      3 d_alloc                                    0.0059
      3 d_instantiate                              0.0234
      1 d_lookup                                   0.0125
    652 __d_lookup                                 1.9405
      3 d_delete                                   0.0117
      3 d_rehash                                   0.0268
      2 d_move                                     0.0033
      1 sys_getcwd                                 0.0017
     14 alloc_inode                                0.0350
      1 destroy_inode                              0.0104
      2 inode_init_once                            0.0069
      1 prune_icache                               0.0020
      1 new_inode                                  0.0078
      1 iget_locked                                0.0052
      4 __insert_inode_hash                        0.0417
      2 generic_delete_inode                       0.0069
      2 generic_forget_inode                       0.0057
      3 iput                                       0.0234
     36 inode_times_differ                         0.4500
     87 update_atime                               0.3884
      5 inode_update_time                          0.0223
      1 wake_up_inode                              0.0208
     38 dnotify_flush                              0.1979
     31 dnotify_parent                             0.1615
     10 lookup_mnt                                 0.0781
      3 copy_namespace                             0.0039
     56 __mark_inode_dirty                         0.2500
      2 write_inode                                0.0250
     10 __sync_single_inode                        0.0184
     11 sync_sb_inodes                             0.0181
      2 writeback_inodes                           0.0125
      2 writeback_acquire                          0.0625
      1 writeback_in_progress                      0.0625
      2 writeback_release                          0.0435
     32 do_mpage_readpage                          0.0274
     14 mpage_writepages                           0.0190
      7 exit_aio                                   0.0486
      1 eventpoll_init_file                        0.0312
      1 set_brk                                    0.0104
      7 create_elf_tables                          0.0075
      1 elf_map                                    0.0045
      3 load_elf_interp                            0.0052
     36 load_elf_binary                            0.0114
      2 de_put                                     0.0089
      1 proc_read_inode                            0.0156
      2 proc_alloc_inode                           0.0156
      1 proc_destroy_inode                         0.0312
      2 proc_get_inode                             0.0066
      2 proc_root_lookup                           0.0156
      3 proc_pid_unhash                            0.0234
      2 proc_file_read                             0.0030
     17 proc_lookup                                0.0590
      1 proc_calc_metrics                          0.0104
     40 get_vmalloc_info                           0.2273
      2 meminfo_read_proc                          0.0040
      2 write_profile                              0.0312
     12 scan_bitmap_block                          0.0103
      6 scan_bitmap                                0.0107
      2 _reiserfs_free_block                       0.0060
      1 reiserfs_discard_all_prealloc              0.0156
      1 use_preallocated_list_if_available         0.0089
     17 reiserfs_allocate_blocknrs                 0.0086
      5 balance_leaf_when_delete                   0.0045
     26 balance_leaf                               0.0021
      1 store_thrown                               0.0104
      2 free_thrown                                0.0179
      1 replace_key                                0.0045
      5 do_balance                                 0.0184
      2 do_balance_mark_leaf_dirty                 0.0139
      5 bin_search_in_dir_item                     0.0284
      5 search_by_entry_key                        0.0101
      3 get_third_component                        0.0312
      1 reiserfs_match                             0.0089
     11 linear_search_in_dir_item                  0.0153
      3 reiserfs_find_entry                        0.0085
      3 reiserfs_lookup                            0.0078
      5 reiserfs_add_entry                         0.0041
      1 new_inode_init                             0.0089
      2 reiserfs_create                            0.0045
      1 de_still_valid                             0.0045
      1 set_ino_in_dir_entry                       0.0156
      3 reiserfs_rename                            0.0011
      2 reiserfs_delete_inode                      0.0066
     37 _make_cpu_key                              0.1779
     92 make_cpu_key                               0.8214
      2 file_capable                               0.0312
      1 _get_block_create_0                        0.0005
     10 reiserfs_get_block                         0.0019
     77 inode2sd                                   0.4010
      2 inode2sd_v1                                0.0139
     52 update_stat_data                           0.1912
     62 reiserfs_update_sd                         0.1384
     14 reiserfs_new_inode                         0.0097
      3 grab_tail_page                             0.0075
      1 reiserfs_truncate_file                     0.0017
      2 lock_buffer_for_writepage                  0.0125
     40 reiserfs_write_full_page                   0.0500
      1 reiserfs_writepage                         0.0156
      3 reiserfs_prepare_write                     0.0170
      5 reiserfs_commit_write                      0.0101
     34 i_attrs_to_sd_attrs                        0.3036
      3 make_le_item_head                          0.0136
     51 reiserfs_file_release                      0.0431
      5 reiserfs_allocate_blocks_for_region        0.0009
      1 reiserfs_copy_from_user_to_file_region     0.0039
      2 reiserfs_check_for_tail_and_convert        0.0036
     10 reiserfs_prepare_file_region_for_write     0.0040
      5 reiserfs_file_write                        0.0025
      2 reiserfs_readdir                           0.0015
     23 create_virtual_node                        0.0180
      6 check_left                                 0.0187
      2 check_right                                0.0063
      9 get_num_ver                                0.0104
      5 set_parameters                             0.0347
      2 is_leaf_removable                          0.0066
      3 are_leaves_removable                       0.0082
      3 get_empty_nodes                            0.0059
      5 get_rfree                                  0.0446
      1 get_far_parent                             0.0014
      2 get_parents                                0.0048
     18 ip_check_balance                           0.0062
      1 dc_check_balance_internal                  0.0007
      3 dc_check_balance_leaf                      0.0055
      3 check_balance                              0.0170
      7 get_direct_parent                          0.0257
      5 get_neighbors                              0.0142
      4 get_virtual_node_size                      0.0500
      3 get_mem_for_virtual_node                   0.0125
     11 wait_tb_buffers_until_unlocked             0.0135
     13 fix_nodes                                  0.0129
     10 unfix_nodes                                0.0260
      1 is_reiserfs_jr                             0.0125
      1 reiserfs_write_super                       0.0069
      3 add_save_link                              0.0055
      3 reiserfs_alloc_inode                       0.0625
     44 reiserfs_dirty_inode                       0.2292
      3 reiserfs_get_unused_objectid               0.0104
      3 reiserfs_release_objectid                  0.0055
      2 leaf_copy_boundary_item                    0.0011
      4 leaf_copy_items_entirely                   0.0052
      1 leaf_copy_items                            0.0025
      4 leaf_delete_items                          0.0089
     15 leaf_insert_into_buf                       0.0177
     10 leaf_paste_in_buffer                       0.0108
      1 leaf_cut_entries                           0.0024
      8 leaf_cut_from_buffer                       0.0065
     14 leaf_delete_items_entirely                 0.0243
     13 leaf_paste_entries                         0.0173
     10 internal_insert_childs                     0.0160
      2 balance_internal                           0.0008
     20 decrement_counters_in_path                 0.2500
      5 pathrelse_and_restore                      0.0625
     26 pathrelse                                  0.4062
    267 is_leaf                                    0.5754
     30 is_internal                                0.1875
    158 is_tree_node                               1.4107
    795 search_by_key                              0.2062
     10 search_for_position_by_key                 0.0102
      2 comp_items                                 0.0208
     14 prepare_for_delete_or_cut                  0.0072
      1 calc_deleted_bytes_number                  0.0021
      4 init_tb_struct                             0.0417
      1 reiserfs_delete_object                     0.0089
      1 maybe_indirect_to_direct                   0.0015
      4 reiserfs_cut_from_item                     0.0032
     10 reiserfs_do_truncate                       0.0075
      2 reiserfs_insert_item                       0.0063
      1 B_IS_IN_TREE                               0.0312
     18 copy_item_head                             0.3750
      3 decrement_bcount                           0.0469
      3 r5_hash                                    0.0375
      1 reiserfs_unmap_buffer                      0.0052
      1 unmap_buffers                              0.0078
      1 indirect2direct                            0.0014
     22 init_journal_hash                          0.6875
      1 get_bitmap_node                            0.0063
      1 set_bit_in_list_bitmap                     0.0089
      5 get_cnode                                  0.0347
      1 push_journal_writer                        0.0625
     15 reiserfs_in_journal                        0.0312
      9 flush_commit_list                          0.0078
      3 find_newer_jl_for_cn                       0.0625
      1 remove_all_from_journal_list               0.0057
      1 _update_journal_header_block               0.0037
      1 flush_older_journal_lists                  0.0063
      1 submit_logged_buffer                       0.0104
     41 kupdate_one_transaction                    0.0777
     28 remove_journal_hash                        0.1458
      2 journal_transaction_should_end             0.0179
      8 reiserfs_wait_on_write_block               0.0556
    171 do_journal_begin_r                         0.2545
      8 journal_begin                              0.1667
     56 journal_mark_dirty                         0.0778
     15 journal_end                                0.3125
     36 can_dirty                                  0.2045
      2 flush_old_commits                          0.0043
     90 check_journal_end                          0.1372
      3 journal_mark_freed                         0.0054
      7 reiserfs_restore_prepared_buffer           0.2188
     44 reiserfs_prepare_for_journal               0.3929
     90 do_journal_end                             0.0277
      2 sd_bytes_number                            0.1250
      2 sd_is_left_mergeable                       0.1250
      4 sd_create_vi                               0.2500
      7 sd_part_size                               0.2188
      5 direct_is_left_mergeable                   0.0347
      3 direct_create_vi                           0.1875
      1 indirect_is_left_mergeable                 0.0089
      2 indirect_create_vi                         0.1250
      1 indirect_part_size                         0.0625
      1 direntry_is_left_mergeable                 0.0625
     13 direntry_create_vi                         0.0325
      3 direntry_check_left                        0.0208
      3 direntry_part_size                         0.0469
      4 copy_semundo                               0.0192
      3 exit_sem                                   0.0089
      1 sysvipc_sem_read_proc                      0.0027
      4 dummy_capable                              0.0833
    117 dummy_vm_enough_memory                     0.6648
      3 dummy_bprm_alloc_security                  0.1875
      2 dummy_bprm_secureexec                      0.0312
      6 dummy_inode_alloc_security                 0.3750
      1 dummy_inode_create                         0.0625
      1 dummy_inode_mkdir                          0.0625
      4 dummy_inode_follow_link                    0.2500
     30 dummy_inode_permission                     1.8750
      2 dummy_inode_getattr                        0.1250
      3 dummy_file_permission                      0.1875
     21 dummy_file_alloc_security                  1.3125
      1 dummy_file_free_security                   0.0625
     38 dummy_file_mmap                            2.3750
      1 dummy_file_fcntl                           0.0625
      1 dummy_task_create                          0.0625
      1 dummy_task_free_security                   0.0625
      2 dummy_d_instantiate                        0.1250
      3 radix_tree_insert                          0.0156
    474 radix_tree_lookup                          5.9250
      2 radix_tree_gang_lookup                     0.0139
      2 radix_tree_delete                          0.0083
      6 __rb_rotate_left                           0.0938
      6 __rb_rotate_right                          0.0938
     41 rb_insert_color                            0.1708
      5 __rb_erase_color                           0.0116
     30 rb_erase                                   0.1172
      2 skip_atoi                                  0.0312
     21 number                                     0.0285
     12 vsnprintf                                  0.0101
      1 sprintf                                    0.0208
    109 atomic_dec_and_lock                        1.3625
      4 __const_udelay                             0.1111
      5 __get_user_4                               0.2174
      7 bad_get_user                               0.7778
     56 memcpy                                     0.5833
    368 _mmx_memcpy                                1.0000
   8390 fast_clear_page                           87.3958
    852 fast_copy_page                             3.3281
     82 mmx_clear_page                             2.5625
      6 mmx_copy_page                              0.1250
     79 strncpy_from_user                          0.7054
     51 clear_user                                 0.5312
    184 strnlen_user                               1.9167
      2 __copy_user_intel                          0.0114
   2436 __copy_to_user_ll                         21.7500
    279 __copy_from_user_ll                        1.7437
      1 init_dev                                   0.0007
      7 release_dev                                0.0045
      1 tty_open                                   0.0012
      1 tty_release                                0.0104
      2 tty_ioctl                                  0.0015
      2 n_tty_ioctl                                0.0017
      1 vt_ioctl                                   0.0001
      1 vc_allocate                                0.0022
      2 con_close                                  0.0208
      1 elv_set_request                            0.0156
      1 blk_recount_segments                       0.0018
     30 blk_rq_map_sg                              0.0893
     10 generic_unplug_device                      0.0893
      2 blk_run_queues                             0.0114
      9 get_request                                0.0134
      1 blk_congestion_wait                        0.0063
    112 __make_request                             0.0778
      7 generic_make_request                       0.0141
      2 submit_bio                                 0.0179
      2 put_io_context                             0.0208
      4 get_io_context                             0.0312
      2 as_work_handler                            0.0179
      9 as_set_request                             0.0625
      1 default_end_request                        0.0625
    145 ide_end_request                            0.4315
      8 start_request                              0.0125
     97 ide_do_request                             0.1102
     40 ide_intr                                   0.1000
    150 ide_inb                                    9.3750
    297 ide_outb                                  18.5625
     28 ide_outl                                   1.7500
      3 SELECT_DRIVE                               0.0375
      2 ide_wait_stat                              0.0066
     36 ide_execute_command                        0.1875
      3 ide_dma_intr                               0.0156
      2 ide_build_sglist                           0.0114
      3 ide_build_dmatable                         0.0075
      1 ide_destroy_dmatable                       0.0208
      6 ide_start_dma                              0.0341
      5 __ide_dma_write                            0.0223
      1 __ide_dma_begin                            0.0125
      2 __ide_dma_end                              0.0125
      5 __ide_do_rw_disk                           0.0027
     19 i8042_interrupt                            0.0540
      6 i8042_timer_func                           0.1250
      1 datagram_poll                              0.0039
      1 rt_check_expire                            0.0037
      1 tcp_poll                                   0.0028
142289 total                                      0.0819


Regards,
Andreas Hartmann

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
  2004-03-29 14:23     ` Chris Mason
  2004-03-29 19:35       ` Andreas Hartmann
  2004-03-29 19:42       ` Andreas Hartmann
@ 2004-04-02  8:19       ` Andreas Hartmann
  2004-04-02 10:23         ` Andrew Morton
  2 siblings, 1 reply; 15+ messages in thread
From: Andreas Hartmann @ 2004-04-02  8:19 UTC (permalink / raw)
  To: Chris Mason; +Cc: Andrew Morton, linux-kernel

Chris Mason wrote:
> On Mon, 2004-03-29 at 01:16, Andreas Hartmann wrote:
>> Andrew Morton wrote:
>> > Andreas Hartmann <andihartmann@freenet.de> wrote:
>> >>
>> >> I tested kernel 2.6.4. While compiling kdelibs and kdebase, I felt, that
>> >>  kernel 2.6 seems to be slower than 2.4.25.
>> >> 
>> >>  So I did some tests to compare the performance directly. Therefore I
>> >>  rebooted for everey test in init 2 (no X).
>> >> 
>> >>  I locally compiled 2.6.5rc2 3 times under 2.6.4 and under 2.4.25 on a
>> >>  reiserfs LVM partition, which resides onto a IDE HD (using DMA) and got
>> >>  the following result:
>> >> 
>> >>  In the middle, compiling under kernel 2.6.4 tooks 9.3% more real time than
>> >>  under 2.4.25.
>> >>  The user-processortime is about the same, but the system-processortime is
>> >>  under 2.6.4 32.9% higher than under 2.4.25.
>> > 
>> > Try mounting your reiserfs filesystems with the `-o nolargeio=1' option.
>> 
>> This didn't help.
>> 
>> > 
>> > If that doesn't help, please run a comparative kernel profile.  See
>> > Documentation/basic_profiling.txt.
>> 
>> I'll do this next.
> 
> You might also want to try 2.6.5-rc2 which has a set of reiserfs fixes
> from 2.4.x.  I'm hoping those will clean things up for you.
> 
> 2.6.5-rc2-mm3 and higher have a number of other reiserfs performance
> fixes, but most of those were not in 2.4.  Trying them out will
> complicate the picture (although I'm still interested in numbers from
> -mm).

Now, I tested 2.6.5-rc3-mm4. Same procedure.
The good news first:
2.6.5-rc3-mm4 is nearly as fast as 2.4.25 - it is about 2% slower than 
2.4.25 (with preemption turned on).

Now the bad news:
The system-processor-time is unchanged abnormal high: it is 34% (!) higher 
than in 2.4.25 (and about 1% more than in 2.4.6).


Btw: Did the other profile outputs help to find the problem?

These are the profile-values for an example run (make of kernel 2.6.5rc2) 
with 2.6.5rc3mm4:

48344 default_idle                             1007.1667
      2 cpu_idle                                   0.0312
      1 exit_thread                                0.0156
      2 flush_thread                               0.0156
      2 release_thread                             0.0250
      2 prepare_to_copy                            0.0156
      2 sys_fork                                   0.0312
      1 sys_vfork                                  0.0156
      4 sys_execve                                 0.0312
      1 __down                                     0.0035
      3 sys_sigreturn                              0.0134
      1 setup_sigcontext                           0.0033
      7 setup_frame                                0.0141
      2 handle_signal                              0.0078
      3 do_signal                                  0.0099
     10 handle_IRQ_event                           0.0893
      4 release_x86_irqs                           0.0312
      7 init_new_context                           0.0199
      1 destroy_context                            0.0125
      3 do_gettimeofday                            0.0170
    143 old_mmap                                   0.3724
    213 kernel_fpu_begin                           3.3281
      2 convert_fxsr_to_user                       0.0048
      2 convert_fxsr_from_user                     0.0060
      3 save_i387                                  0.0110
      3 sched_clock                                0.0208
     36 delay_pmtmr                                1.1250
     10 get_offset_pmtmr                           0.0046
      3 pte_alloc_one                              0.0375
      2 pgd_alloc                                  0.0625
      2 pgd_free                                   0.0312
   2289 do_page_fault                              1.7211
      1 try_to_wake_up                             0.0052
      6 wake_up_forked_process                     0.0163
     85 finish_task_switch                         0.5903
     18 schedule                                   0.0163
      1 preempt_schedule                           0.0125
     16 __wake_up                                  0.1667
      1 __wake_up_sync                             0.0078
      2 wait_for_completion                        0.0078
      1 io_schedule                                0.0312
    529 __might_sleep                              2.5433
      5 __put_task_struct                          0.0195
      3 add_wait_queue                             0.0312
      1 remove_wait_queue                          0.0069
      1 prepare_to_wait                            0.0078
     28 dup_task_struct                            0.1167
      4 mm_init                                    0.0179
      7 mm_alloc                                   0.1094
      2 __mmdrop                                   0.0250
      4 mmput                                      0.0227
      4 mm_release                                 0.0208
     48 copy_mm                                    0.0411
      8 count_open_files                           0.1667
     23 copy_files                                 0.0271
      4 unshare_files                              0.0417
     37 copy_process                               0.0129
      8 do_fork                                    0.0220
     49 release_task                               0.0988
     11 put_files_struct                           0.0573
     51 exit_notify                                0.0270
     13 do_exit                                    0.0119
      1 next_thread                                0.0312
      5 do_group_exit                              0.0284
      1 sys_exit_group                             0.0312
      4 eligible_child                             0.0167
      8 wait_task_zombie                           0.0156
      9 sys_wait4                                  0.0148
      1 sys_waitpid                                0.0233
      1 .text.lock.exit                            0.0047
     25 current_kernel_time                        0.3906
      1 get_jiffies_64                             0.0208
   3912 __do_softirq                              30.5625
      7 tasklet_action                             0.0625
     23 __mod_timer                                0.0553
      1 del_timer                                  0.0057
    198 run_timer_softirq                          0.4267
      1 sys_getpid                                 0.0625
      1 sys_getppid                                0.0312
      1 sys_getgid                                 0.0625
      1 sys_getegid                                0.0625
      2 free_uid                                   0.0125
      3 flush_signal_handlers                      0.0375
     20 get_signal_to_deliver                      0.0223
     30 sigprocmask                                0.1562
     17 sys_rt_sigprocmask                         0.0425
     14 do_sigaction                               0.0273
      7 sys_rt_sigaction                           0.0208
    129 groups_search                              1.1518
     69 in_group_p                                 0.5391
      4 sys_newuname                               0.0227
      1 getrusage                                  0.0015
      1 sys_getrusage                              0.0156
      1 __queue_work                               0.0069
      6 alloc_pidmap                               0.0117
      2 rcu_do_batch                               0.0208
      1 rcu_start_batch                            0.0156
      5 rcu_check_quiescent_state                  0.0347
      7 rcu_process_callbacks                      0.0273
      1 kthread_should_stop                        0.0312
      2 acct_process                               0.0143
      6 remove_from_page_cache                     0.0750
      1 filemap_fdatawrite                         0.0312
     13 add_to_page_cache                          0.0580
      2 add_to_page_cache_lru                      0.0250
     22 page_waitqueue                             0.4583
      1 wait_on_page_bit                           0.0052
     76 unlock_page                                0.7917
      7 end_page_writeback                         0.0625
    874 find_get_page                              9.1042
      7 find_lock_page                             0.0312
      2 find_or_create_page                        0.0104
      2 find_get_pages                             0.0179
    108 find_get_pages_tag                         0.7500
     85 do_generic_mapping_read                    0.0871
     47 file_read_actor                            0.1836
     70 __generic_file_aio_read                    0.1287
     30 generic_file_read                          0.1705
    162 filemap_nopage                             0.1841
     21 generic_file_mmap                          0.3281
     13 read_cache_page                            0.0232
      1 remove_suid                                0.0078
     10 generic_write_checks                       0.0149
     28 mempool_alloc                              0.0761
      1 mempool_alloc_slab                         0.0312
     93 bad_range                                  0.8304
     74 prep_new_page                              0.7708
    465 free_hot_cold_page                         1.8164
      4 free_hot_page                              0.2500
   1657 buffered_rmqueue                           3.5711
    356 __alloc_pages                              0.4363
      1 __free_pages                               0.0125
      2 free_pages                                 0.0417
     73 nr_free_pages                              0.9125
      1 get_zone_counts                            0.0078
      2 balance_dirty_pages_ratelimited            0.0125
      2 wb_kupdate                                 0.0069
      3 do_writepages                              0.0375
     53 __set_page_dirty_nobuffers                 0.2760
      1 test_clear_page_dirty                      0.0057
     27 clear_page_dirty_for_io                    0.4219
     38 test_clear_page_writeback                  0.2159
     29 test_set_page_writeback                    0.1295
      2 mapping_tagged                             0.0179
     77 file_ra_state_init                         1.6042
     90 do_page_cache_readahead                    0.2250
     84 page_cache_readahead                       0.1694
      2 cache_grow                                 0.0032
    161 kmem_cache_alloc                           1.4375
     20 __kmalloc                                  0.1250
     95 kmem_cache_free                            1.1875
     18 kfree                                      0.1607
     10 reap_timer_fnc                             0.0189
      4 activate_page                              0.0192
    241 mark_page_accessed                         5.0208
      2 lru_cache_add                              0.0208
    128 lru_cache_add_active                       1.3333
     19 lru_add_drain                              0.1979
    356 __page_cache_release                       1.8542
     76 release_pages                              0.1827
      3 __pagevec_lru_add                          0.0117
    205 __pagevec_lru_add_active                   0.7537
      1 pagevec_lookup_tag                         0.0125
      1 truncate_inode_pages                       0.0014
      5 shrink_list                                0.0039
      1 blk_queue_bounce                           0.0089
     88 clear_page_tables                          0.4583
    265 pte_alloc_map                              1.3802
    221 copy_page_range                            0.2558
    667 zap_pte_range                              1.7370
     13 zap_pmd_range                              0.1161
     15 unmap_page_range                           0.1339
     36 unmap_vmas                                 0.0662
     64 do_wp_page                                 0.0800
    692 do_anonymous_page                          1.4417
    684 do_no_page                                 0.8906
    663 handle_mm_fault                            1.4799
     54 remove_shared_vm_struct                    0.3750
     12 sys_brk                                    0.0417
    109 find_vma_prepare                           0.9732
     14 __vma_link_rb                              0.2188
     23 __vma_link                                 0.1437
     16 vma_link                                   0.1000
      4 __insert_vm_struct                         0.0278
      8 can_vma_merge_before                       0.1000
     46 can_vma_merge_after                        0.5750
    119 vma_merge                                  0.1730
    311 do_mmap_pgoff                              0.1735
     66 get_unmapped_area                          0.2062
    548 find_vma                                   5.7083
     36 find_vma_prev                              0.3750
      1 expand_stack                               0.0052
     22 free_pgtables                              0.1375
     10 unmap_vma                                  0.0781
      3 unmap_vma_list                             0.0625
     22 unmap_region                               0.0982
     20 detach_vmas_to_be_unmapped                 0.1786
     16 split_vma                                  0.0357
     23 do_munmap                                  0.0575
     16 sys_munmap                                 0.1250
     20 do_brk                                     0.0368
     23 exit_mmap                                  0.0575
    473 page_add_rmap                              2.6875
    304 page_remove_rmap                           1.0000
    295 __pte_chain_free                           2.6339
    109 pte_chain_alloc                            0.5677
     72 free_page_and_swap_cache                   0.6429
     10 can_share_swap_page                        0.0893
      4 si_swapinfo                                0.0357
      3 sys_access                                 0.0089
     34 filp_open                                  0.3036
     51 dentry_open                                0.0966
     59 get_unused_fd                              0.1418
     20 fd_install                                 0.3125
     29 sys_open                                   0.2014
     32 filp_close                                 0.2222
     41 sys_close                                  0.2562
      5 default_llseek                             0.0208
      2 sys_llseek                                 0.0078
     52 vfs_read                                   0.1625
      9 vfs_write                                  0.0281
     14 sys_read                                   0.1250
      4 sys_write                                  0.0357
     46 get_empty_filp                             0.1797
     22 fput                                       0.6875
     67 __fput                                     0.2204
     23 fget                                       0.3594
     42 fget_light                                 0.3281
     19 file_move                                  0.1979
     26 file_kill                                  0.4062
     57 __constant_c_and_count_memset              0.3958
      5 bh_waitq_head                              0.1562
     47 wake_up_buffer                             0.9792
     19 unlock_buffer                              0.2375
      3 __wait_on_buffer                           0.0125
      3 __set_page_buffers                         0.0469
    159 __find_get_block_slow                      0.4141
      4 inode_has_buffers                          0.1250
     41 __set_page_dirty_buffers                   0.1424
      2 invalidate_inode_buffers                   0.0179
      2 create_buffers                             0.0114
      1 __getblk_slow                              0.0035
     43 __brelse                                   0.6719
     76 bh_lru_install                             0.3393
    473 __find_get_block                           1.8477
     30 __getblk                                   0.2679
     29 __bread                                    0.3625
      3 create_empty_buffers                       0.0187
     14 __block_write_full_page                    0.0139
      3 __block_prepare_write                      0.0027
      2 block_prepare_write                        0.0250
      2 block_write_full_page                      0.0078
      5 submit_bh                                  0.0104
      1 check_ttfb_buffer                          0.0104
      1 drop_buffers                               0.0045
      1 try_to_free_buffers                        0.0048
      2 alloc_buffer_head                          0.0208
      3 init_buffer_head                           0.0625
     19 bio_alloc                                  0.0457
     11 bio_clone                                  0.0688
      2 sync_supers                                0.0083
     23 nr_blockdev_pages                          0.2396
      2 chrdev_open                                0.0038
      1 cdev_get                                   0.0052
     77 generic_fillattr                           0.4813
     46 vfs_getattr                                0.2396
     31 vfs_fstat                                  0.3875
     43 cp_new_stat64                              0.1344
      1 sys_stat64                                 0.0156
     20 sys_fstat64                                0.3125
      2 count                                      0.0312
     90 copy_strings                               0.1480
      2 copy_strings_kernel                        0.0250
      1 put_dirty_page                             0.0030
      9 setup_arg_pages                            0.0176
      9 open_exec                                  0.0375
      2 kernel_read                                0.0208
      3 exec_mmap                                  0.0110
     15 flush_old_exec                             0.0066
      2 prepare_binprm                             0.0096
      7 compute_creds                              0.0243
      9 search_binary_handler                      0.0128
      4 do_execve                                  0.0063
      1 set_binfmt                                 0.0063
      5 pipe_wait                                  0.0260
     15 pipe_readv                                 0.0195
      1 pipe_read                                  0.0156
      9 pipe_writev                                0.0097
      3 pipe_write                                 0.0469
      2 pipe_release                               0.0089
      1 pipe_write_fasync                          0.0069
      1 pipe_write_release                         0.0156
      1 get_pipe_inode                             0.0052
     53 getname                                    0.2548
     30 vfs_permission                             0.1042
     28 permission                                 0.2188
      1 get_write_access                           0.0125
      2 deny_write_access                          0.0250
      1 path_release                               0.0156
      1 cached_lookup                              0.0069
      5 real_lookup                                0.0184
     25 follow_mount                               0.1736
     22 do_lookup                                  0.1250
    453 link_path_walk                             0.1827
     84 path_lookup                                0.2625
      2 __lookup_hash                              0.0089
      1 lookup_hash                                0.0208
      5 __user_walk                                0.0521
      1 unlock_rename                              0.0125
      4 vfs_create                                 0.0147
    128 may_open                                   0.2963
     33 open_namei                                 0.0290
      1 vfs_mkdir                                  0.0039
      1 vfs_unlink                                 0.0023
      1 sys_unlink                                 0.0030
      1 vfs_rename_other                           0.0031
      1 sys_rename                                 0.0018
     25 page_getlink                               0.1302
     23 page_follow_link                           0.0464
      1 set_close_on_exec                          0.0156
      2 expand_files                               0.0179
      2 locate_fd                                  0.0069
      1 sys_dup2                                   0.0033
      2 generic_file_fcntl                         0.0046
      1 fasync_helper                              0.0042
      3 sys_ioctl                                  0.0042
      3 filldir64                                  0.0094
      1 max_select_fd                              0.0045
      2 do_select                                  0.0028
     39 locks_remove_posix                         0.1434
     37 locks_remove_flock                         0.1927
      6 steal_locks                                0.0288
      1 d_callback                                 0.0156
      1 d_free                                     0.0156
     67 dput                                       0.1074
      8 d_alloc                                    0.0156
      3 d_instantiate                              0.0234
    644 __d_lookup                                 1.9167
      6 d_rehash                                   0.0536
      9 alloc_inode                                0.0216
      1 inode_init_once                            0.0039
      4 clear_inode                                0.0227
      1 prune_icache                               0.0018
      5 new_inode                                  0.0312
      3 get_new_inode_fast                         0.0110
      1 iget_locked                                0.0052
      6 __insert_inode_hash                        0.0625
      4 generic_delete_inode                       0.0132
      8 iput                                       0.0625
     33 inode_times_differ                         0.4125
     69 update_atime                               0.3080
      6 inode_update_time                          0.0268
      1 i_waitq_head                               0.0312
      2 wake_up_inode                              0.0417
      2 is_bad_inode                               0.0250
     35 dnotify_flush                              0.1823
     44 dnotify_parent                             0.2292
      5 lookup_mnt                                 0.0391
      3 copy_namespace                             0.0039
     53 __mark_inode_dirty                         0.1840
     10 __sync_single_inode                        0.0216
      1 __writeback_single_inode                   0.0052
     12 sync_sb_inodes                             0.0179
      1 writeback_acquire                          0.0312
      4 writeback_in_progress                      0.2500
      3 writeback_release                          0.0652
     22 do_mpage_readpage                          0.0188
      1 mpage_readpages                            0.0024
     41 mpage_writepages                           0.0483
      4 exit_aio                                   0.0278
      4 eventpoll_init_file                        0.1250
      5 set_brk                                    0.0521
     24 create_elf_tables                          0.0259
      9 elf_map                                    0.0402
     12 load_elf_interp                            0.0192
     35 load_elf_binary                            0.0104
      2 de_put                                     0.0089
      1 proc_delete_inode                          0.0069
      3 proc_get_inode                             0.0094
      3 proc_pid_unhash                            0.0234
      1 proc_file_read                             0.0015
     20 proc_lookup                                0.0694
     41 get_vmalloc_info                           0.2330
      2 meminfo_read_proc                          0.0040
      3 write_profile                              0.0469
     44 scan_bitmap_block                          0.0377
      9 scan_bitmap                                0.0165
      2 _reiserfs_free_block                       0.0060
      2 reiserfs_free_block                        0.0312
      1 reiserfs_discard_all_prealloc              0.0156
      2 determine_prealloc_size                    0.0139
     15 reiserfs_allocate_blocknrs                 0.0076
      1 reiserfs_claim_blocks_to_be_allocated      0.0208
      1 reiserfs_release_claimed_blocks            0.0208
      3 reiserfs_can_fit_pages                     0.0312
      3 balance_leaf_when_delete                   0.0027
     21 balance_leaf                               0.0017
      3 free_thrown                                0.0268
      1 reiserfs_invalidate_buffer                 0.0208
      4 do_balance                                 0.0147
      4 bin_search_in_dir_item                     0.0227
      9 search_by_entry_key                        0.0181
      5 get_third_component                        0.0521
      3 linear_search_in_dir_item                  0.0042
      4 reiserfs_find_entry                        0.0114
      1 reiserfs_lookup                            0.0026
     10 reiserfs_add_entry                         0.0082
      2 new_inode_init                             0.0179
      4 reiserfs_create                            0.0089
      4 reiserfs_unlink                            0.0050
      1 reiserfs_rename                            0.0004
      1 reiserfs_delete_inode                      0.0037
     33 _make_cpu_key                              0.1587
     88 make_cpu_key                               0.7857
      1 file_capable                               0.0156
      1 reiserfs_get_block                         0.0002
     72 inode2sd                                   0.3750
      4 inode2sd_v1                                0.0278
     28 update_stat_data                           0.1029
     59 reiserfs_update_sd                         0.1272
     14 reiserfs_new_inode                         0.0097
      1 grab_tail_page                             0.0025
     10 reiserfs_truncate_file                     0.0179
     73 reiserfs_write_full_page                   0.0830
      4 reiserfs_writepage                         0.0625
     10 i_attrs_to_sd_attrs                        0.0893
      1 invalidatepage_can_drop                    0.0069
      3 reiserfs_invalidatepage                    0.0134
      3 make_le_item_head                          0.0136
     50 reiserfs_file_release                      0.0434
     29 reiserfs_allocate_blocks_for_region        0.0055
      4 reiserfs_copy_from_user_to_file_region     0.0167
      7 reiserfs_commit_page                       0.0273
      9 reiserfs_submit_file_region_for_write      0.0117
      5 reiserfs_check_for_tail_and_convert        0.0089
     49 reiserfs_prepare_file_region_for_write     0.0199
     30 reiserfs_file_write                        0.0151
      1 reiserfs_readdir                           0.0007
     15 create_virtual_node                        0.0117
      4 check_left                                 0.0125
      1 check_right                                0.0031
     15 get_num_ver                                0.0174
      5 set_parameters                             0.0347
      1 are_leaves_removable                       0.0027
      4 get_rfree                                  0.0357
      1 is_left_neighbor_in_cache                  0.0063
      3 get_parents                                0.0072
     18 ip_check_balance                           0.0062
      1 dc_check_balance_internal                  0.0007
      5 dc_check_balance_leaf                      0.0092
      2 dc_check_balance                           0.0417
      4 check_balance                              0.0227
      3 get_direct_parent                          0.0110
      7 get_neighbors                              0.0199
      1 get_virtual_node_size                      0.0125
      2 get_mem_for_virtual_node                   0.0083
      6 wait_tb_buffers_until_unlocked             0.0074
     18 fix_nodes                                  0.0184
      6 unfix_nodes                                0.0170
      1 is_reiserfs_jr                             0.0125
      3 add_save_link                              0.0055
      1 remove_save_link                           0.0045
      1 reiserfs_alloc_inode                       0.0208
     62 reiserfs_dirty_inode                       0.3229
      1 reiserfs_get_unused_objectid               0.0035
      1 leaf_copy_boundary_item                    0.0005
      3 leaf_copy_items_entirely                   0.0039
      1 leaf_copy_items                            0.0025
      4 leaf_define_dest_src_infos                 0.0093
      1 leaf_shift_left                            0.0052
      2 leaf_delete_items                          0.0045
     22 leaf_insert_into_buf                       0.0259
      9 leaf_paste_in_buffer                       0.0097
      3 leaf_cut_entries                           0.0072
     12 leaf_cut_from_buffer                       0.0097
      7 leaf_delete_items_entirely                 0.0122
     13 leaf_paste_entries                         0.0173
      7 internal_insert_childs                     0.0112
      1 internal_delete_pointers_items             0.0021
      1 internal_insert_key                        0.0030
      1 balance_internal_when_delete               0.0018
      2 balance_internal                           0.0008
     29 decrement_counters_in_path                 0.3625
      1 pathrelse_and_restore                      0.0125
     21 pathrelse                                  0.3281
    274 is_leaf                                    0.5905
     29 is_internal                                0.1812
    167 is_tree_node                               1.4911
    716 search_by_key                              0.1857
     14 search_for_position_by_key                 0.0143
      1 comp_items                                 0.0104
      5 prepare_for_delete_or_cut                  0.0026
      2 calc_deleted_bytes_number                  0.0042
      9 init_tb_struct                             0.0938
      1 padd_item                                  0.0312
      2 maybe_indirect_to_direct                   0.0030
      6 reiserfs_cut_from_item                     0.0048
      8 reiserfs_do_truncate                       0.0060
      2 reiserfs_paste_into_item                   0.0066
      1 reiserfs_insert_item                       0.0031
      3 B_IS_IN_TREE                               0.0938
     10 copy_item_head                             0.2083
      3 decrement_bcount                           0.0469
      3 r5_hash                                    0.0375
      3 indirect2direct                            0.0038
     22 init_journal_hash                          0.6875
      5 get_cnode                                  0.0312
      2 free_cnode                                 0.0139
      1 reiserfs_check_lock_depth                  0.0625
     89 reiserfs_in_journal                        0.1794
      2 submit_ordered_buffer                      0.0312
      1 write_ordered_chunk                        0.0125
      1 reiserfs_free_jh                           0.0089
      5 reiserfs_add_ordered_list                  0.0260
     16 write_ordered_buffers                      0.0263
     47 reiserfs_async_progress_wait               0.3264
     11 flush_commit_list                          0.0107
      2 find_newer_jl_for_cn                       0.0417
      2 flush_journal_list                         0.0013
      7 dirty_one_transaction                      0.0547
     33 remove_journal_hash                        0.1719
      1 alloc_journal_list                         0.0069
     20 reiserfs_wait_on_write_block               0.1389
     15 wake_queued_writers                        0.2344
    106 do_journal_begin_r                         0.1656
     36 journal_begin                              0.1731
     59 journal_mark_dirty                         0.0899
     40 journal_end                                0.2083
      1 remove_from_transaction                    0.0028
     30 can_dirty                                  0.1705
     65 check_journal_end                          0.1016
      1 journal_mark_freed                         0.0020
      8 reiserfs_restore_prepared_buffer           0.0417
     40 reiserfs_prepare_for_journal               0.3125
    133 do_journal_end                             0.0452
      1 sd_bytes_number                            0.0625
      1 sd_is_left_mergeable                       0.0625
      1 sd_create_vi                               0.0625
      2 sd_part_size                               0.0625
      2 direct_is_left_mergeable                   0.0139
      1 direct_create_vi                           0.0625
      3 direct_part_size                           0.1875
      1 indirect_bytes_number                      0.0312
      3 indirect_part_size                         0.1875
      6 direntry_is_left_mergeable                 0.3750
      8 direntry_create_vi                         0.0200
      1 direntry_check_left                        0.0069
      1 direntry_part_size                         0.0156
      3 copy_semundo                               0.0144
      1 exit_sem                                   0.0030
      1 capable                                    0.0104
      4 dummy_capable                              0.0833
    110 dummy_vm_enough_memory                     0.6250
      1 dummy_bprm_alloc_security                  0.0625
      1 dummy_bprm_set_security                    0.0625
      1 dummy_bprm_secureexec                      0.0156
      5 dummy_inode_alloc_security                 0.3125
      2 dummy_inode_unlink                         0.1250
      6 dummy_inode_follow_link                    0.3750
     20 dummy_inode_permission                     1.2500
      1 dummy_inode_getattr                        0.0625
      6 dummy_file_permission                      0.3750
     18 dummy_file_alloc_security                  1.1250
      3 dummy_file_free_security                   0.1875
      2 dummy_file_ioctl                           0.1250
     32 dummy_file_mmap                            2.0000
      4 dummy_task_wait                            0.2500
      1 dummy_d_instantiate                        0.0625
      2 kobject_get                                0.0250
      2 kobject_put                                0.0625
      2 radix_tree_preload                         0.0125
     13 __rb_rotate_left                           0.2031
     10 __rb_rotate_right                          0.1562
     58 rb_insert_color                            0.2417
      6 __rb_erase_color                           0.0139
     29 rb_erase                                   0.1133
      3 skip_atoi                                  0.0469
     21 number                                     0.0285
     17 vsnprintf                                  0.0144
      2 vsprintf                                   0.0417
      2 sprintf                                    0.0417
     76 atomic_dec_and_lock                        0.9500
      1 __delay                                    0.0312
      4 __get_user_4                               0.1739
      3 bad_get_user                               0.3333
     38 memcpy                                     0.3958
    355 _mmx_memcpy                                0.9647
   8365 fast_clear_page                           87.1354
    827 fast_copy_page                             3.2305
     83 mmx_clear_page                             2.5938
      1 mmx_copy_page                              0.0208
     77 direct_strncpy_from_user                   0.6875
     55 direct_clear_user                          0.5729
    149 direct_strnlen_user                        1.5521
      2 __copy_user_intel                          0.0114
   2408 __copy_to_user_ll                         21.5000
    247 __copy_from_user_ll                        1.5437
      1 write_null                                 0.0625
      3 init_dev                                   0.0019
      4 release_dev                                0.0026
      3 tty_open                                   0.0035
      1 tty_fasync                                 0.0035
      2 tty_ioctl                                  0.0015
      2 vt_ioctl                                   0.0002
      1 con_open                                   0.0057
      1 con_close                                  0.0063
     21 blk_rq_map_sg                              0.0656
      4 generic_unplug_device                      0.0357
      6 get_request                                0.0089
     73 __make_request                             0.0507
     12 generic_make_request                       0.0242
      3 submit_bio                                 0.0117
      1 put_io_context                             0.0104
      1 get_io_context                             0.0078
      1 blk_backing_dev_unplug                     0.0208
      3 as_work_handler                            0.0268
      3 as_set_request                             0.0208
      1 mii_link_ok                                0.0125
    181 ide_end_request                            0.5387
      4 start_request                              0.0068
     60 ide_do_request                             0.0682
     28 ide_intr                                   0.0700
     92 ide_inb                                    5.7500
    162 ide_outb                                  10.1250
      9 ide_outl                                   0.5625
      1 SELECT_DRIVE                               0.0125
      4 ide_wait_stat                              0.0132
     23 ide_execute_command                        0.1198
      5 ide_dma_intr                               0.0260
      5 ide_build_sglist                           0.0284
     11 ide_build_dmatable                         0.0275
      1 ide_start_dma                              0.0057
      4 __ide_dma_write                            0.0167
      1 __ide_dma_end                              0.0063
      2 __ide_do_rw_disk                           0.0011
      2 ide_do_rw_disk                             0.0208
     19 i8042_interrupt                            0.0540
      2 i8042_timer_func                           0.0417
      3 sock_poll                                  0.0469
      1 fn_hash_lookup                             0.0037
      8 ret_from_intr                              0.2963
    261 system_call                                5.9318
      2 syscall_call                               0.1818
     15 syscall_exit                               1.3636
     33 error_code                                 0.5893
    174 device_not_available                       4.1429
  90826 total                                      0.0533


Regards,
Andreas Hartmann

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
  2004-04-02  8:19       ` Andreas Hartmann
@ 2004-04-02 10:23         ` Andrew Morton
  2004-04-02 20:53           ` Andreas Hartmann
  0 siblings, 1 reply; 15+ messages in thread
From: Andrew Morton @ 2004-04-02 10:23 UTC (permalink / raw)
  To: Andreas Hartmann; +Cc: mason, linux-kernel

Andreas Hartmann <andihartmann@freenet.de> wrote:
>
> Now, I tested 2.6.5-rc3-mm4. Same procedure.
>  The good news first:
>  2.6.5-rc3-mm4 is nearly as fast as 2.4.25 - it is about 2% slower than 
>  2.4.25 (with preemption turned on).
> 
>  Now the bad news:
>  The system-processor-time is unchanged abnormal high: it is 34% (!) higher 
>  than in 2.4.25 (and about 1% more than in 2.4.6).
> 
> 
>  Btw: Did the other profile outputs help to find the problem?
> 
>  These are the profile-values for an example run (make of kernel 2.6.5rc2) 
>  with 2.6.5rc3mm4:

Spending a lot of time on do_softirq() while compiling stuff is peculiar.

What device drivers are running at the time?  disk/network/usb/etc?

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
  2004-04-02 10:23         ` Andrew Morton
@ 2004-04-02 20:53           ` Andreas Hartmann
  2004-04-02 21:13             ` Andrew Morton
  0 siblings, 1 reply; 15+ messages in thread
From: Andreas Hartmann @ 2004-04-02 20:53 UTC (permalink / raw)
  To: Andrew Morton; +Cc: mason, linux-kernel

Andrew Morton wrote:
> Andreas Hartmann <andihartmann@freenet.de> wrote:
>>
>> Now, I tested 2.6.5-rc3-mm4. Same procedure.
>>  The good news first:
>>  2.6.5-rc3-mm4 is nearly as fast as 2.4.25 - it is about 2% slower than 
>>  2.4.25 (with preemption turned on).
>> 
>>  Now the bad news:
>>  The system-processor-time is unchanged abnormal high: it is 34% (!) higher 
>>  than in 2.4.25 (and about 1% more than in 2.4.6).
>> 
>> 
>>  Btw: Did the other profile outputs help to find the problem?
>> 
>>  These are the profile-values for an example run (make of kernel 2.6.5rc2) 
>>  with 2.6.5rc3mm4:
> 
> Spending a lot of time on do_softirq() while compiling stuff is peculiar.
> 
> What device drivers are running at the time?  disk/network/usb/etc?

Module                  Size  Used by    Not tainted
eepro100               19828   1  (autoclean)
mii                     2480   0  (autoclean) [eepro100]
sis900                 13036   1  (autoclean)
crc32                   2880   0  (autoclean) [sis900]
usb-storage            26416   0  (unused)
scsi_mod               87488   0  [usb-storage]
uhci                   25436   0  (unused)
usbcore                62316   0  [usb-storage uhci]
lvm-mod                44416  12  (autoclean)
unix                   15308  13  (autoclean)

These are all modules (drivers), which are running - in both cases (2.4.25 
and 2.6.x).


Regards,
Andreas Hartmann

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
  2004-04-02 20:53           ` Andreas Hartmann
@ 2004-04-02 21:13             ` Andrew Morton
  2004-04-03  0:23               ` Andreas Hartmann
  0 siblings, 1 reply; 15+ messages in thread
From: Andrew Morton @ 2004-04-02 21:13 UTC (permalink / raw)
  To: Andreas Hartmann; +Cc: mason, linux-kernel

Andreas Hartmann <andihartmann@freenet.de> wrote:
>
> > What device drivers are running at the time?  disk/network/usb/etc?
> 
> Module                  Size  Used by    Not tainted
> eepro100               19828   1  (autoclean)
> mii                     2480   0  (autoclean) [eepro100]
> sis900                 13036   1  (autoclean)
> crc32                   2880   0  (autoclean) [sis900]
> usb-storage            26416   0  (unused)
> scsi_mod               87488   0  [usb-storage]
> uhci                   25436   0  (unused)
> usbcore                62316   0  [usb-storage uhci]
> lvm-mod                44416  12  (autoclean)
> unix                   15308  13  (autoclean)

No.  I mean which drivers were actually doing significant amounts of work
during the test?

(you appear to not have any disks)

^ permalink raw reply	[flat|nested] 15+ messages in thread

* Re: Very poor performance with 2.6.4
  2004-04-02 21:13             ` Andrew Morton
@ 2004-04-03  0:23               ` Andreas Hartmann
  0 siblings, 0 replies; 15+ messages in thread
From: Andreas Hartmann @ 2004-04-03  0:23 UTC (permalink / raw)
  To: Andrew Morton; +Cc: mason, linux-kernel

Andrew Morton wrote:
> Andreas Hartmann <andihartmann@freenet.de> wrote:
>>
>> > What device drivers are running at the time?  disk/network/usb/etc?
[..]
> No.  I mean which drivers were actually doing significant amounts of work
> during the test?
> 
> (you appear to not have any disks)

Surely do I have disks - I forgot them :-). I've got two IDE-HD's, 
/dev/hda and /dev/hdb. /dev/hdb is switched off during boot with hdparm. 
On /dev/hda, the whole work is done.
There is a cdrom and a cd-writer on /dev/hdd and /dev/hdc. They have been 
not used during the tests.

I think it is best, if I post the whole boot-entries from messages:


Apr  2 08:14:56 athlon kernel: PI: PCI Interrupt Routing Table 
[\_SB_.PCI0._PRT]
Apr  2 08:14:56 athlon kernel: ACPI: PCI Interrupt Link [LNKA] (IRQs 1 3 4 
5 6 7 10 *11 12 14 15)
Apr  2 08:14:56 athlon kernel: ACPI: PCI Interrupt Link [LNKB] (IRQs 1 3 4 
5 6 7 *10 11 12 14 15)
Apr  2 08:14:56 athlon kernel: ACPI: PCI Interrupt Link [LNKC] (IRQs 1 3 4 
*5 6 7 10 11 12 14 15)
Apr  2 08:14:56 athlon kernel: ACPI: PCI Interrupt Link [LNKD] (IRQs 1 3 4 
5 6 7 10 *11 12 14 15)
Apr  2 08:14:56 athlon kernel: ACPI: PCI Interrupt Link [ALKA] (IRQs 20)
Apr  2 08:14:56 athlon kernel: ACPI: PCI Interrupt Link [ALKB] (IRQs 21)
Apr  2 08:14:56 athlon kernel: ACPI: PCI Interrupt Link [ALKC] (IRQs 22)
Apr  2 08:14:56 athlon kernel: ACPI: PCI Interrupt Link [ALKD] (IRQs 23)
Apr  2 08:14:56 athlon kernel: IOAPIC[0]: Set PCI routing entry (2-16 -> 
0xa9 -> IRQ 16 Mode:1 Active:1)
Apr  2 08:14:56 athlon kernel: 00:00:08[A] -> 2-16 -> IRQ 16
Apr  2 08:14:56 athlon kernel: IOAPIC[0]: Set PCI routing entry (2-17 -> 
0xb1 -> IRQ 17 Mode:1 Active:1)
Apr  2 08:14:56 athlon kernel: 00:00:08[B] -> 2-17 -> IRQ 17
Apr  2 08:14:56 athlon kernel: IOAPIC[0]: Set PCI routing entry (2-18 -> 
0xb9 -> IRQ 18 Mode:1 Active:1)
Apr  2 08:14:56 athlon kernel: 00:00:08[C] -> 2-18 -> IRQ 18
Apr  2 08:14:56 athlon kernel: IOAPIC[0]: Set PCI routing entry (2-19 -> 
0xc1 -> IRQ 19 Mode:1 Active:1)
Apr  2 08:14:56 athlon kernel: 00:00:08[D] -> 2-19 -> IRQ 19
Apr  2 08:14:56 athlon kernel: _CRS returns NULL! Using IRQ 21 fordevice 
(PCI Interrupt Link [ALKB]).
Apr  2 08:14:56 athlon kernel: ACPI: PCI Interrupt Link [ALKB] enabled at 
IRQ 21
Apr  2 08:14:56 athlon kernel: IOAPIC[0]: Set PCI routing entry (2-21 -> 
0xc9 -> IRQ 21 Mode:1 Active:1)
Apr  2 08:14:56 athlon kernel: 00:00:10[A] -> 2-21 -> IRQ 21
Apr  2 08:14:56 athlon kernel: _CRS returns NULL! Using IRQ 20 fordevice 
(PCI Interrupt Link [ALKA]).
Apr  2 08:14:56 athlon kernel: ACPI: PCI Interrupt Link [ALKA] enabled at 
IRQ 20
Apr  2 08:14:56 athlon kernel: IOAPIC[0]: Set PCI routing entry (2-20 -> 
0xd1 -> IRQ 20 Mode:1 Active:1)
Apr  2 08:14:56 athlon kernel: 00:00:11[A] -> 2-20 -> IRQ 20
Apr  2 08:14:56 athlon kernel: _CRS returns NULL! Using IRQ 22 fordevice 
(PCI Interrupt Link [ALKC]).
Apr  2 08:14:56 athlon kernel: ACPI: PCI Interrupt Link [ALKC] enabled at 
IRQ 22
Apr  2 08:14:56 athlon kernel: IOAPIC[0]: Set PCI routing entry (2-22 -> 
0xd9 -> IRQ 22 Mode:1 Active:1)
Apr  2 08:14:56 athlon kernel: 00:00:11[C] -> 2-22 -> IRQ 22
Apr  2 08:14:56 athlon kernel: _CRS returns NULL! Using IRQ 23 fordevice 
(PCI Interrupt Link [ALKD]).
Apr  2 08:14:56 athlon kernel: ACPI: PCI Interrupt Link [ALKD] enabled at 
IRQ 23
Apr  2 08:14:56 athlon kernel: IOAPIC[0]: Set PCI routing entry (2-23 -> 
0xe1 -> IRQ 23 Mode:1 Active:1)
Apr  2 08:14:56 athlon kernel: 00:00:11[D] -> 2-23 -> IRQ 23
Apr  2 08:14:56 athlon kernel: number of MP IRQ sources: 15.
Apr  2 08:14:56 athlon kernel: number of IO-APIC #2 registers: 24.
Apr  2 08:14:56 athlon kernel: testing the IO APIC.......................
Apr  2 08:14:56 athlon kernel: IO APIC #2......
Apr  2 08:14:56 athlon kernel: .... register #00: 02000000
Apr  2 08:14:56 athlon kernel: .......    : physical APIC id: 02
Apr  2 08:14:56 athlon kernel: .......    : Delivery Type: 0
Apr  2 08:14:56 athlon kernel: .......    : LTS          : 0
Apr  2 08:14:56 athlon kernel: .... register #01: 00178003
Apr  2 08:14:56 athlon kernel: .......     : max redirection entries: 0017
Apr  2 08:14:56 athlon kernel: .......     : PRQ implemented: 1
Apr  2 08:14:56 athlon kernel: .......     : IO APIC version: 0003
Apr  2 08:14:56 athlon kernel: .... IRQ redirection table:
Apr  2 08:14:56 athlon kernel:  NR Log Phy Mask Trig IRR Pol Stat Dest 
Deli Vect:
Apr  2 08:14:56 athlon kernel:  00 000 00  1    0    0   0   0    0    0    00
Apr  2 08:14:56 athlon kernel:  01 001 01  0    0    0   0   0    1    1    39
Apr  2 08:14:56 athlon kernel:  02 001 01  0    0    0   0   0    1    1    31
Apr  2 08:14:56 athlon kernel:  03 001 01  0    0    0   0   0    1    1    41
Apr  2 08:14:56 athlon kernel:  04 001 01  0    0    0   0   0    1    1    49
Apr  2 08:14:56 athlon kernel:  05 001 01  0    0    0   0   0    1    1    51
Apr  2 08:14:56 athlon kernel:  06 001 01  0    0    0   0   0    1    1    59
Apr  2 08:14:56 athlon kernel:  07 001 01  0    0    0   0   0    1    1    61
Apr  2 08:14:56 athlon kernel:  08 001 01  0    0    0   0   0    1    1    69
Apr  2 08:14:56 athlon kernel:  09 001 01  0    1    0   1   0    1    1    71
Apr  2 08:14:56 athlon kernel:  0a 001 01  0    0    0   0   0    1    1    79
Apr  2 08:14:56 athlon kernel:  0b 001 01  0    0    0   0   0    1    1    81
Apr  2 08:14:56 athlon kernel:  0c 001 01  0    0    0   0   0    1    1    89
Apr  2 08:14:56 athlon kernel:  0d 001 01  0    0    0   0   0    1    1    91
Apr  2 08:14:56 athlon kernel:  0e 001 01  0    0    0   0   0    1    1    99
Apr  2 08:14:56 athlon kernel:  0f 001 01  0    0    0   0   0    1    1    A1
Apr  2 08:14:56 athlon kernel:  10 001 01  1    1    0   1   0    1    1    A9
Apr  2 08:14:56 athlon kernel:  11 001 01  1    1    0   1   0    1    1    B1
Apr  2 08:14:56 athlon kernel:  12 001 01  1    1    0   1   0    1    1    B9
Apr  2 08:14:56 athlon kernel:  13 001 01  1    1    0   1   0    1    1    C1
Apr  2 08:14:56 athlon kernel:  14 001 01  1    1    0   1   0    1    1    D1
Apr  2 08:14:56 athlon kernel:  15 001 01  1    1    0   1   0    1    1    C9
Apr  2 08:14:56 athlon kernel:  16 001 01  1    1    0   1   0    1    1    D9
Apr  2 08:14:56 athlon kernel:  17 001 01  1    1    0   1   0    1    1    E1
Apr  2 08:14:56 athlon kernel: IRQ to pin mappings:
Apr  2 08:14:56 athlon kernel: IRQ0 -> 0:2
Apr  2 08:14:56 athlon kernel: IRQ1 -> 0:1
Apr  2 08:14:56 athlon kernel: IRQ3 -> 0:3
Apr  2 08:14:56 athlon kernel: IRQ4 -> 0:4
Apr  2 08:14:56 athlon kernel: IRQ5 -> 0:5
Apr  2 08:14:56 athlon kernel: IRQ6 -> 0:6
Apr  2 08:14:56 athlon kernel: IRQ7 -> 0:7
Apr  2 08:14:56 athlon kernel: IRQ8 -> 0:8
Apr  2 08:14:56 athlon kernel: IRQ9 -> 0:9
Apr  2 08:14:56 athlon kernel: IRQ10 -> 0:10
Apr  2 08:14:56 athlon kernel: IRQ11 -> 0:11
Apr  2 08:14:56 athlon kernel: IRQ12 -> 0:12
Apr  2 08:14:56 athlon kernel: IRQ13 -> 0:13
Apr  2 08:14:56 athlon kernel: IRQ14 -> 0:14
Apr  2 08:14:56 athlon kernel: IRQ15 -> 0:15
Apr  2 08:14:56 athlon kernel: IRQ16 -> 0:16
Apr  2 08:14:56 athlon kernel: IRQ17 -> 0:17
Apr  2 08:14:56 athlon kernel: IRQ18 -> 0:18
Apr  2 08:14:56 athlon kernel: IRQ19 -> 0:19
Apr  2 08:14:56 athlon kernel: IRQ20 -> 0:20
Apr  2 08:14:56 athlon kernel: IRQ21 -> 0:21
Apr  2 08:14:56 athlon kernel: IRQ22 -> 0:22
Apr  2 08:14:56 athlon kernel: IRQ23 -> 0:23
Apr  2 08:14:56 athlon kernel: .................................... done.
Apr  2 08:14:56 athlon kernel: PCI: Using ACPI for IRQ routing
Apr  2 08:14:56 athlon kernel: PCI: if you experience problems, try using 
option 'pci=noacpi' or even 'acpi=off'
Apr  2 08:14:56 athlon kernel: Initializing Cryptographic API
Apr  2 08:14:56 athlon kernel: PCI: Via IRQ fixup for 0000:00:10.0, from 
11 to 5
Apr  2 08:14:56 athlon kernel: PCI: Via IRQ fixup for 0000:00:10.1, from 
10 to 5
Apr  2 08:14:56 athlon kernel: Uniform Multi-Platform E-IDE driver 
Revision: 7.00alpha2
Apr  2 08:14:56 athlon kernel: ide: Assuming 33MHz system bus speed for 
PIO modes; override with idebus=xx
Apr  2 08:14:56 athlon kernel: VP_IDE: IDE controller at PCI slot 0000:00:11.1
Apr  2 08:14:56 athlon kernel: VP_IDE: chipset revision 6
Apr  2 08:14:56 athlon kernel: VP_IDE: not 100% native mode: will probe 
irqs later
Apr  2 08:14:56 athlon kernel: VP_IDE: VIA vt8235 (rev 00) IDE UDMA133 
controller on pci0000:00:11.1
Apr  2 08:14:56 athlon kernel:     ide0: BM-DMA at 0xe400-0xe407, BIOS 
settings: hda:DMA, hdb:DMA
Apr  2 08:14:56 athlon kernel:     ide1: BM-DMA at 0xe408-0xe40f, BIOS 
settings: hdc:DMA, hdd:DMA
Apr  2 08:14:56 athlon kernel: hda: WDC WD205AA, ATA DISK drive
Apr  2 08:14:56 athlon kernel: hdb: WDC WD450AA-00BAA0, ATA DISK drive
Apr  2 08:14:56 athlon kernel: Using anticipatory io scheduler
Apr  2 08:14:56 athlon kernel: ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
Apr  2 08:14:56 athlon kernel: hdc: PLEXTOR CD-R PX-W1610A, ATAPI 
CD/DVD-ROM drive
Apr  2 08:14:56 athlon kernel: hdd: ATAPI CDROM 48X, ATAPI CD/DVD-ROM drive
Apr  2 08:14:56 athlon kernel: ide1 at 0x170-0x177,0x376 on irq 15
Apr  2 08:14:56 athlon kernel: hda: max request size: 128KiB
Apr  2 08:14:56 athlon kernel: hda: 40079088 sectors (20520 MB) w/2048KiB 
Cache, CHS=39761/16/63, UDMA(66)
Apr  2 08:14:56 athlon kernel:  hda: hda1 hda2 hda3 hda4 < hda5 hda6 hda7 
hda8 hda9 hda10 >
Apr  2 08:14:56 athlon kernel: hdb: max request size: 128KiB
Apr  2 08:14:56 athlon kernel: hdb: 87930864 sectors (45020 MB) w/2048KiB 
Cache, CHS=65535/16/63, UDMA(66)
Apr  2 08:14:56 athlon kernel:  hdb: hdb1 hdb2 < hdb5 hdb6 hdb7 hdb8 hdb9 
hdb10 hdb11 hdb12 hdb13 hdb14 hdb15 >
Apr  2 08:14:56 athlon kernel: ieee1394: raw1394: /dev/raw1394 device 
initialized
Apr  2 08:14:56 athlon kernel: mice: PS/2 mouse device common for all mice
Apr  2 08:14:56 athlon kernel: serio: i8042 AUX port at 0x60,0x64 irq 12
Apr  2 08:14:56 athlon kernel: input: PS/2 Logitech Mouse on isa0060/serio1
Apr  2 08:14:56 athlon kernel: serio: i8042 KBD port at 0x60,0x64 irq 1
Apr  2 08:14:56 athlon kernel: input: AT Translated Set 2 keyboard on 
isa0060/serio0
Apr  2 08:14:56 athlon kernel: NET: Registered protocol family 2
Apr  2 08:14:56 athlon kernel: IP: routing cache hash table of 4096 
buckets, 32Kbytes
Apr  2 08:14:56 athlon kernel: TCP: Hash tables configured (established 
32768 bind 65536)
Apr  2 08:14:56 athlon kernel: ip_conntrack version 2.1 (4095 buckets, 
32760 max) - 296 bytes per conntrack
Apr  2 08:14:56 athlon kernel: ip_tables: (C) 2000-2002 Netfilter core team
Apr  2 08:14:56 athlon kernel: ipt_recent v0.3.1: Stephen Frost 
<sfrost@snowman.net>.  http://snowman.net/projects/ipt_recent/
Apr  2 08:14:56 athlon kernel: arp_tables: (C) 2002 David S. Miller
Apr  2 08:14:56 athlon kernel: ACPI: (supports S0 S1 S4 S5)
Apr  2 08:14:56 athlon kernel: found reiserfs format "3.5" with standard 
journal
Apr  2 08:14:56 athlon kernel: reiserfs: using ordered data mode
Apr  2 08:14:56 athlon kernel: Reiserfs journal params: device hda1, size 
8192, journal first block 18, max trans len 1024, max batch 900, max 
commit age 30, max trans age 30
Apr  2 08:14:56 athlon kernel: reiserfs: checking transaction log (hda1) 
for (hda1)
Apr  2 08:14:56 athlon kernel: Using tea hash to sort names
Apr  2 08:14:56 athlon kernel: VFS: Mounted root (reiserfs filesystem).
Apr  2 08:14:56 athlon kernel: Freeing unused kernel memory: 144k freed
Apr  2 08:14:56 athlon kernel: NET: Registered protocol family 1
Apr  2 08:14:56 athlon kernel: Adding 514040k swap on /dev/hda9. 
Priority:-1 extents:1
Apr  2 08:14:56 athlon kernel: device-mapper: 4.1.0-ioctl (2003-12-10) 
initialised: dm@uk.sistina.com
Apr  2 08:14:56 athlon kernel: hdc: ATAPI 40X CD-ROM CD-R/RW drive, 2048kB 
Cache, DMA
Apr  2 08:14:56 athlon kernel: Uniform CD-ROM driver Revision: 3.20
Apr  2 08:14:56 athlon kernel: hdd: ATAPI CD-ROM drive, 128kB Cache, UDMA(33)
Apr  2 08:14:56 athlon kernel: found reiserfs format "3.6" with standard 
journal
Apr  2 08:14:56 athlon kernel: reiserfs: using ordered data mode
Apr  2 08:14:56 athlon kernel: Reiserfs journal params: device hda8, size 
8192, journal first block 18, max trans len 1024, max batch 900, max 
commit age 30, max trans age 30
Apr  2 08:14:56 athlon kernel: reiserfs: checking transaction log (hda8) 
for (hda8)
Apr  2 08:14:56 athlon kernel: Using r5 hash to sort names
Apr  2 08:14:56 athlon kernel: found reiserfs format "3.6" with standard 
journal
Apr  2 08:14:56 athlon kernel: reiserfs: using ordered data mode
Apr  2 08:14:56 athlon kernel: Reiserfs journal params: device dm-13, size 
8192, journal first block 18, max trans len 1024, max batch 900, max 
commit age 30, max trans age 30
Apr  2 08:14:56 athlon kernel: reiserfs: checking transaction log (dm-13) 
for (dm-13)
Apr  2 08:14:56 athlon kernel: Using r5 hash to sort names
Apr  2 08:14:56 athlon kernel: found reiserfs format "3.6" with standard 
journal
Apr  2 08:14:56 athlon kernel: reiserfs: using ordered data mode
Apr  2 08:14:56 athlon kernel: Reiserfs journal params: device hda7, size 
8192, journal first block 18, max trans len 1024, max batch 900, max 
commit age 30, max trans age 30
Apr  2 08:14:56 athlon kernel: reiserfs: checking transaction log (hda7) 
for (hda7)
Apr  2 08:14:56 athlon kernel: Using r5 hash to sort names
Apr  2 08:14:56 athlon kernel: found reiserfs format "3.6" with standard 
journal
Apr  2 08:14:56 athlon kernel: reiserfs: using ordered data mode
Apr  2 08:14:56 athlon kernel: Reiserfs journal params: device dm-8, size 
8192, journal first block 18, max trans len 1024, max batch 900, max 
commit age 30, max trans age 30
Apr  2 08:14:56 athlon kernel: reiserfs: checking transaction log (dm-8) 
for (dm-8)
Apr  2 08:14:56 athlon kernel: Using r5 hash to sort names
Apr  2 08:14:56 athlon kernel: found reiserfs format "3.6" with standard 
journal
Apr  2 08:14:56 athlon kernel: reiserfs: using ordered data mode
Apr  2 08:14:56 athlon kernel: Reiserfs journal params: device dm-11, size 
8192, journal first block 18, max trans len 1024, max batch 900, max 
commit age 30, max trans age 30
Apr  2 08:14:56 athlon kernel: reiserfs: checking transaction log (dm-11) 
for (dm-11)
Apr  2 08:14:56 athlon kernel: Using r5 hash to sort names
Apr  2 08:14:56 athlon kernel: found reiserfs format "3.6" with standard 
journal
Apr  2 08:14:56 athlon kernel: reiserfs: using ordered data mode
Apr  2 08:14:56 athlon kernel: Reiserfs journal params: device dm-10, size 
8192, journal first block 18, max trans len 1024, max batch 900, max 
commit age 30, max trans age 30
Apr  2 08:14:56 athlon kernel: reiserfs: checking transaction log (dm-10) 
for (dm-10)
Apr  2 08:14:56 athlon kernel: Using r5 hash to sort names
Apr  2 08:14:56 athlon kernel: found reiserfs format "3.6" with standard 
journal
Apr  2 08:14:56 athlon kernel: reiserfs: using ordered data mode
Apr  2 08:14:56 athlon kernel: Reiserfs journal params: device dm-9, size 
8192, journal first block 18, max trans len 1024, max batch 900, max 
commit age 30, max trans age 30
Apr  2 08:14:56 athlon kernel: reiserfs: checking transaction log (dm-9) 
for (dm-9)
Apr  2 08:14:56 athlon kernel: Using r5 hash to sort names
Apr  2 08:14:56 athlon kernel: found reiserfs format "3.6" with standard 
journal
Apr  2 08:14:56 athlon kernel: reiserfs: using ordered data mode
Apr  2 08:14:56 athlon kernel: Reiserfs journal params: device hda5, size 
8192, journal first block 18, max trans len 1024, max batch 900, max 
commit age 30, max trans age 30
Apr  2 08:14:56 athlon kernel: reiserfs: checking transaction log (hda5) 
for (hda5)
Apr  2 08:14:56 athlon kernel: Using r5 hash to sort names
Apr  2 08:14:56 athlon kernel: blk: queue dfd55c00, I/O limit 4095Mb (mask 
0xffffffff)
Apr  2 08:14:56 athlon kernel: blk: queue dfd55800, I/O limit 4095Mb (mask 
0xffffffff)
Apr  2 08:14:56 athlon kernel: parport0: PC-style at 0x378 (0x778), irq 7 
[PCSPP(,...)]
Apr  2 08:14:56 athlon kernel: lp0: using parport0 (interrupt-driven).
Apr  2 08:14:56 athlon kernel: usbcore: registered new driver usbfs
Apr  2 08:14:56 athlon kernel: usbcore: registered new driver hub
Apr  2 08:14:56 athlon kernel: USB Universal Host Controller Interface 
driver v2.2
Apr  2 08:14:56 athlon kernel: uhci_hcd 0000:00:10.0: VIA Technologies, 
Inc. USB
Apr  2 08:14:56 athlon kernel: uhci_hcd 0000:00:10.0: irq 21, io base 0000d800
Apr  2 08:14:56 athlon kernel: uhci_hcd 0000:00:10.0: new USB bus 
registered, assigned bus number 1
Apr  2 08:14:56 athlon kernel: hub 1-0:1.0: USB hub found
Apr  2 08:14:56 athlon kernel: hub 1-0:1.0: 2 ports detected
Apr  2 08:14:56 athlon kernel: uhci_hcd 0000:00:10.1: VIA Technologies, 
Inc. USB (#2)
Apr  2 08:14:56 athlon kernel: uhci_hcd 0000:00:10.1: irq 21, io base 0000dc00
Apr  2 08:14:56 athlon kernel: uhci_hcd 0000:00:10.1: new USB bus 
registered, assigned bus number 2
Apr  2 08:14:56 athlon kernel: hub 2-0:1.0: USB hub found
Apr  2 08:14:56 athlon kernel: hub 2-0:1.0: 2 ports detected
Apr  2 08:14:56 athlon kernel: uhci_hcd 0000:00:10.2: VIA Technologies, 
Inc. USB (#3)
Apr  2 08:14:56 athlon kernel: uhci_hcd 0000:00:10.2: irq 21, io base 0000e000
Apr  2 08:14:56 athlon kernel: uhci_hcd 0000:00:10.2: new USB bus 
registered, assigned bus number 3
Apr  2 08:14:56 athlon kernel: hub 3-0:1.0: USB hub found
Apr  2 08:14:56 athlon kernel: hub 3-0:1.0: 2 ports detected
Apr  2 08:14:56 athlon kernel: SCSI subsystem initialized
Apr  2 08:14:56 athlon kernel: Initializing USB Mass Storage driver...
Apr  2 08:14:56 athlon kernel: usbcore: registered new driver usb-storage
Apr  2 08:14:56 athlon kernel: USB Mass Storage support registered.
Apr  2 08:14:56 athlon kernel: Serial: 8250/16550 driver $Revision: 1.90 $ 
8 ports, IRQ sharing disabled
Apr  2 08:14:56 athlon kernel: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
Apr  2 08:14:56 athlon kernel: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
Apr  2 08:14:56 athlon kernel: sis900.c: v1.08.07 11/02/2003
Apr  2 08:14:56 athlon kernel: eth0: SiS 900 Internal MII PHY transceiver 
found at address 1.
Apr  2 08:14:56 athlon kernel: eth0: Using transceiver found at address 1 
as default
Apr  2 08:14:56 athlon kernel: eth0: SiS 900 PCI Fast Ethernet at 0xd000, 
IRQ 17, 00:40:33:e2:43:71.
Apr  2 08:14:56 athlon kernel: eth0: Media Link Off
Apr  2 08:14:56 athlon kernel: eepro100.c:v1.09j-t 9/29/99 Donald Becker 
http://www.scyld.com/network/eepro100.html
Apr  2 08:14:56 athlon kernel: eepro100.c: $Revision: 1.36 $ 2000/11/17 
Modified by Andrey V. Savochkin <saw@saw.sw.com.sg> and others
Apr  2 08:14:56 athlon kernel: eth1: 0000:00:0c.0, 00:02:B3:8F:F9:11, IRQ 18.
Apr  2 08:14:56 athlon kernel:   Board assembly 751767-004, Physical 
connectors present: RJ45
Apr  2 08:14:56 athlon kernel:   Primary interface chip i82555 PHY #1.
Apr  2 08:14:56 athlon kernel:     Secondary interface chip i82555.
Apr  2 08:14:56 athlon kernel:   General self-test: passed.
Apr  2 08:14:56 athlon kernel:   Serial sub-system self-test: passed.
Apr  2 08:14:56 athlon kernel:   Internal registers self-test: passed.
Apr  2 08:14:56 athlon kernel:   ROM checksum self-test: passed (0x3258698e).


Regards,
Andreas Hartmann

^ permalink raw reply	[flat|nested] 15+ messages in thread

end of thread, other threads:[~2004-04-03  0:23 UTC | newest]

Thread overview: 15+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2004-03-28 20:02 Very poor performance with 2.6.4 Andreas Hartmann
2004-03-28 20:24 ` Matt H.
2004-03-28 21:11 ` Sasa U
2004-03-29  4:07 ` Andrew Morton
2004-03-29  6:16   ` Andreas Hartmann
2004-03-29 14:23     ` Chris Mason
2004-03-29 19:35       ` Andreas Hartmann
2004-03-29 19:42       ` Andreas Hartmann
2004-04-02  8:19       ` Andreas Hartmann
2004-04-02 10:23         ` Andrew Morton
2004-04-02 20:53           ` Andreas Hartmann
2004-04-02 21:13             ` Andrew Morton
2004-04-03  0:23               ` Andreas Hartmann
2004-03-29 17:41   ` Andreas Hartmann
     [not found] <1EOM0-3oS-17@gated-at.bofh.it>
2004-03-28 22:47 ` Andi Kleen

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox