From: Michael Buesch <fsdeveloper@yahoo.de>
To: Andrew Morton <akpm@osdl.org>
Cc: linux-kernel@vger.kernel.org, linux-ide@vger.kernel.org,
Willy Gardiol <gardiol@libero.it>
Subject: Re: [2.6] system is very slow during disk access
Date: Thu, 7 Aug 2003 00:44:25 +0200 [thread overview]
Message-ID: <200308070044.41198.fsdeveloper@yahoo.de> (raw)
In-Reply-To: <20030806150434.53c4fa8c.akpm@osdl.org>
[-- Attachment #1: clearsigned data --]
[-- Type: Text/Plain, Size: 1116 bytes --]
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
On Thursday 07 August 2003 00:04, Andrew Morton wrote:
> Please boot the 2.6 machine with "profile=1" on the kernel boot command
> line.
>
> start the `dd', do a `readprofile -r', wait ten seconds, do
>
> readprofile -m /wherever/System.map
>
> then post the results.
I've done this twice and appended the results to this mail.
But I've captured a few other interesting things in the syslog.
After doing a
$ hdparm -c1 -u1 -d1 -X69 /dev/hda
I saw this in my syslog:
Aug 7 00:32:05 lfs kernel: blk: queue c049195c, I/O limit 4095Mb (mask 0xffffffff)
Aug 7 00:32:05 lfs kernel: hda: Speed warnings UDMA 3/4/5 is not functional.
The onboard IDE controller is a UDMA-100 controller
and the disks do run in this mode, too.
- --
Regards Michael Buesch [ http://www.8ung.at/tuxsoft ]
Penguin on this machine: Linux 2.6.0-test2 - i386
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.2.1 (GNU/Linux)
iD8DBQE/MYTVoxoigfggmSgRAlG4AJ9AzwetBUAZBT/l/ltkwMAWKHsGWwCcCX9H
aN2KwzLzeYhYrU9y7IUgM6c=
=r/G9
-----END PGP SIGNATURE-----
[-- Attachment #2: profile-results.1 --]
[-- Type: text/plain, Size: 16131 bytes --]
1 restore_sigcontext 0,0033
1 setup_frame 0,0021
1722 system_call 39,1364
13 syscall_call 1,1818
6 syscall_exit 0,5455
3 device_not_available 0,0714
8 handle_IRQ_event 0,0816
1 save_i387 0,0055
18 delay_tsc 0,6667
1 apm_bios_call 0,0045
1 queue_empty 0,0500
1 check_apm_user 0,0189
4 do_page_fault 0,0034
11 schedule 0,0116
273 __wake_up 3,1379
1 sys_sched_get_priority_max 0,0286
2 remove_wait_queue 0,0189
2 sys_setitimer 0,0080
19 current_kernel_time 0,3167
234 do_softirq 1,4625
5 run_timer_softirq 0,0117
1 schedule_timeout 0,0058
2 group_send_sig_info 0,0021
3 get_signal_to_deliver 0,0039
1 adjust_abs_time 0,0039
2 __remove_from_page_cache 0,0208
9 add_to_page_cache 0,0303
30 page_waitqueue 0,6383
7 wait_on_page_bit 0,0400
55 unlock_page 0,6962
5 find_get_page 0,0510
54 find_lock_page 0,1682
10 remove_suid 0,1000
508 generic_file_aio_write_nolock 0,1636
75 generic_file_write_nolock 0,5172
36 generic_file_write 0,3396
1 generic_file_readv 0,0069
33 mempool_alloc 0,0979
1 mempool_alloc_slab 0,0476
13 bad_range 0,1287
8 prep_new_page 0,1081
64 free_hot_cold_page 0,2452
1 free_hot_page 0,0909
75 buffered_rmqueue 0,1918
14 __alloc_pages 0,0194
1 __free_pages 0,0139
1 __get_page_state 0,0092
28 balance_dirty_pages_ratelimited 0,1958
23 __set_page_dirty_nobuffers 0,1150
22 test_clear_page_dirty 0,3793
75 kmem_cache_alloc 1,1538
26 __kmalloc 0,2203
33 kmem_cache_free 0,4648
15 kfree 0,1596
1 reap_timer_fnc 0,0021
78 mark_page_accessed 1,5600
1 lru_cache_add_active 0,0093
1 lru_add_drain 0,0104
8 release_pages 0,0213
8 __pagevec_release_nonlru 0,0593
22 __pagevec_lru_add 0,0880
1 shrink_slab 0,0029
20 shrink_list 0,0142
25 shrink_cache 0,0346
3 refill_inactive_zone 0,0023
1 shrink_zone 0,0065
1 blk_queue_bounce 0,0128
1 zap_pte_range 0,0026
1 do_wp_page 0,0010
6 do_anonymous_page 0,0102
2 find_vma 0,0241
9 page_referenced 0,0552
1 free_page_and_swap_cache 0,0062
55 vfs_read 0,2052
2 do_sync_write 0,0111
47 vfs_write 0,1754
74 sys_read 0,7957
57 sys_write 0,6129
3 fput 0,1200
5 fget 0,0735
72 fget_light 0,5255
1 __set_page_buffers 0,0133
2 __clear_page_buffers 0,0164
18 __find_get_block_slow 0,0647
2 mark_buffer_async_write 0,0870
1 buffer_insert_list 0,0093
1 invalidate_inode_buffers 0,0090
4 create_buffers 0,0258
1 __getblk_slow 0,0033
23 mark_buffer_dirty 0,3067
40 __brelse 0,7018
830 __find_get_block 3,8073
112 __getblk 1,4933
98 __bread 1,7193
10 set_bh_page 0,1639
1 try_to_release_page 0,0101
18 create_empty_buffers 0,1161
7 unmap_underlying_metadata 0,0753
2 __block_write_full_page 0,0022
1374 __block_prepare_write 1,4870
70 __block_commit_write 0,5036
2 block_read_full_page 0,0031
29 block_prepare_write 0,4462
2 block_commit_write 0,0435
41 generic_commit_write 0,2680
4 submit_bh 0,0118
1 check_ttfb_buffer 0,0125
4 drop_buffers 0,0209
3 try_to_free_buffers 0,0160
1 recalc_bh_state 0,0169
7 alloc_buffer_head 0,0769
6 free_buffer_head 0,0606
18 bio_alloc 0,0442
1 generic_fillattr 0,0056
1 cp_new_stat64 0,0044
1 pipe_poll 0,0083
3 follow_mount 0,0216
1 do_lookup 0,0069
11 link_path_walk 0,0051
2 path_lookup 0,0064
1 open_namei 0,0010
1 sys_ioctl 0,0016
1 poll_freewait 0,0149
3 __pollwait 0,0175
3 do_select 0,0048
3 sys_select 0,0026
1 do_poll 0,0054
3 dput 0,0058
13 __d_lookup 0,0415
1 alloc_inode 0,0030
1 shrink_icache_memory 0,0263
1 find_inode_fast 0,0116
86 inode_times_differ 1,2464
2 update_atime 0,0100
89 inode_update_time 0,5266
72 dnotify_parent 0,4586
4 __mark_inode_dirty 0,0170
1 write_inode 0,0141
1 writeback_inodes 0,0060
14 mpage_writepages 0,0183
1 proc_read_inode 0,0175
4 proc_lookup 0,0150
1 kstat_read_proc 0,0014
6 write_profile 0,0909
20 scan_bitmap_block 0,0181
7 scan_bitmap 0,0136
6 use_preallocated_list_if_available 0,0513
7 reiserfs_allocate_blocknrs 0,0035
33 balance_leaf 0,0031
13 free_thrown 0,1250
20 do_balance 0,0766
11 do_balance_mark_leaf_dirty 0,0902
133 _make_cpu_key 0,7189
39 make_cpu_key 0,4149
1 file_capable 0,0192
1 restart_transaction 0,0090
146 reiserfs_get_block 0,0291
48 inode2sd 0,3221
64 update_stat_data 0,2570
232 reiserfs_update_sd 0,5358
1 lock_buffer_for_writepage 0,0069
49 reiserfs_write_full_page 0,0641
5 reiserfs_writepage 0,0877
32 reiserfs_prepare_write 0,2286
172 reiserfs_commit_write 0,4057
8 i_attrs_to_sd_attrs 0,0748
11 reiserfs_releasepage 0,0714
23 reiserfs_file_write 0,0144
1 get_num_ver 0,0012
4 set_parameters 0,0315
1 is_leaf_removable 0,0034
1 get_empty_nodes 0,0018
3 get_lfree 0,0288
10 get_rfree 0,1010
24 get_parents 0,0603
43 ip_check_balance 0,0147
11 check_balance 0,0738
4 get_direct_parent 0,0205
4 get_neighbors 0,0117
4 get_virtual_node_size 0,0500
8 get_mem_for_virtual_node 0,0369
2 clear_all_dirty_bits 0,0556
83 wait_tb_buffers_until_unlocked 0,0956
27 fix_nodes 0,0250
83 unfix_nodes 0,2365
748 leaf_paste_in_buffer 1,0580
3 leaf_cut_from_buffer 0,0028
1 internal_insert_childs 0,0021
13 decrement_counters_in_path 0,1646
19 pathrelse_and_restore 0,2436
55 pathrelse 1,0000
194 is_leaf 0,4369
161 is_internal 1,1583
167 is_tree_node 1,6058
2811 search_by_key 0,7901
35 search_for_position_by_key 0,0362
33 init_tb_struct 0,4177
6 reiserfs_paste_into_item 0,0218
7 B_IS_IN_TREE 0,3333
8 copy_item_head 0,2222
2 comp_short_keys 0,0247
4 decrement_bcount 0,0741
2 reiserfs_check_lock_depth 0,4000
1 push_journal_writer 0,1429
2 pop_journal_writer 0,2857
1 dump_journal_writers 0,0164
49 reiserfs_in_journal 0,1029
53 reiserfs_wait_on_write_block 0,3841
104 do_journal_begin_r 0,1600
6 journal_begin 0,1395
1 journal_prepare 0,1429
71 journal_mark_dirty 0,0967
13 journal_end 0,3023
4 remove_from_transaction 0,0110
100 check_journal_end 0,1548
19 reiserfs_update_inode_transaction 0,3585
2 reiserfs_inode_in_this_transaction 0,0476
44 reiserfs_restore_prepared_buffer 1,4194
67 reiserfs_prepare_for_journal 0,6768
69 do_journal_end 0,0238
1 sd_is_left_mergeable 0,1429
6 indirect_bytes_number 0,2609
6 indirect_decrement_key 0,0472
6 indirect_is_left_mergeable 0,0517
4 radix_tree_preload 0,0252
16 radix_tree_insert 0,0792
106 radix_tree_lookup 1,3766
22 radix_tree_delete 0,0987
8 number 0,0135
10 vsnprintf 0,0092
2 vsprintf 0,0465
7 atomic_dec_and_lock 0,0833
2 __const_udelay 0,0541
103 memcpy 1,8727
1 memset 0,0400
5 strncpy_from_user 0,0549
321 clear_user 4,5211
1 __clear_user 0,0323
2 __copy_user_intel 0,0116
2 __copy_to_user_ll 0,0192
499 __copy_from_user_ll 4,7981
49 read_zero 0,1008
1 tty_poll 0,0085
2 normal_poll 0,0062
1 pty_chars_in_buffer 0,0137
69 blk_rq_map_sg 0,2156
1 blk_congestion_wait 0,0077
107 __make_request 0,0845
16 generic_make_request 0,0362
17 submit_bio 0,1604
1 get_io_context 0,0079
1 get_stats 0,0083
270 ide_end_request 0,8157
19 ide_do_request 0,0178
15 ide_intr 0,0358
75 ide_inb 6,2500
1 ide_outb 0,0769
149 ide_outbsync 11,4615
4 ide_outsl 0,2222
26 ide_execute_command 0,1461
1 SELECT_DRIVE 0,0133
2 default_end_request 0,2222
3 __ide_do_rw_disk 0,0016
1 ide_do_rw_disk 0,0147
2 ide_dma_intr 0,0108
6 ide_build_sglist 0,0349
5 ide_build_dmatable 0,0128
1 ide_start_dma 0,0062
1 __ide_dma_write 0,0050
2 i8042_interrupt 0,0036
1 i8042_timer_func 0,0161
40 raid0_make_request 0,1108
2 sock_ioctl 0,0031
11 sock_poll 0,2292
2 sock_alloc_send_pskb 0,0042
1 sock_def_readable 0,0077
1 alloc_skb 0,0044
2 tcp_poll 0,0055
2 unix_stream_sendmsg 0,0020
2 unix_stream_recvmsg 0,0016
2 unix_ioctl 0,0097
8 unix_poll 0,0530
15452 gesamt 0,0065
[-- Attachment #3: profile-results.2 --]
[-- Type: text/plain, Size: 14421 bytes --]
1 restore_sigcontext 0,0033
1 setup_frame 0,0021
987 system_call 22,4318
5 syscall_call 0,4545
1 syscall_exit 0,0909
3 handle_IRQ_event 0,0306
1 do_gettimeofday 0,0070
11 delay_tsc 0,4074
1 do_page_fault 0,0008
5 schedule 0,0053
146 __wake_up 1,6782
1 remove_wait_queue 0,0094
1 do_setitimer 0,0026
1 sys_setitimer 0,0040
8 current_kernel_time 0,1333
116 do_softirq 0,7250
1 tasklet_action 0,0099
1 add_timer 0,0061
1 run_timer_softirq 0,0023
1 group_send_sig_info 0,0011
6 add_to_page_cache 0,0202
22 page_waitqueue 0,4681
7 wait_on_page_bit 0,0400
30 unlock_page 0,3797
3 find_get_page 0,0306
40 find_lock_page 0,1246
9 remove_suid 0,0900
296 generic_file_aio_write_nolock 0,0953
33 generic_file_write_nolock 0,2276
18 generic_file_write 0,1698
2 generic_file_readv 0,0138
20 mempool_alloc 0,0593
1 mempool_alloc_slab 0,0476
7 bad_range 0,0693
4 prep_new_page 0,0541
22 free_hot_cold_page 0,0843
33 buffered_rmqueue 0,0844
4 __alloc_pages 0,0055
1 __get_page_state 0,0092
25 balance_dirty_pages_ratelimited 0,1748
20 __set_page_dirty_nobuffers 0,1000
10 test_clear_page_dirty 0,1724
1 cache_init_objs 0,0088
31 kmem_cache_alloc 0,4769
21 __kmalloc 0,1780
5 kmem_cache_free 0,0704
19 kfree 0,2021
59 mark_page_accessed 1,1800
1 lru_cache_add_active 0,0093
1 lru_add_drain 0,0104
1 release_pages 0,0027
12 __pagevec_lru_add 0,0480
1 shrink_slab 0,0029
2 shrink_list 0,0014
5 shrink_cache 0,0069
2 refill_inactive_zone 0,0016
1 balance_pgdat 0,0026
1 blk_queue_bounce 0,0128
1 zap_pte_range 0,0026
2 do_anonymous_page 0,0034
1 do_no_page 0,0011
3 do_mmap_pgoff 0,0019
1 get_unmapped_area 0,0033
1 detach_vmas_to_be_unmapped 0,0105
3 page_referenced 0,0184
1 add_to_swap 0,0044
1 dentry_open 0,0020
1 get_unused_fd 0,0025
42 vfs_read 0,1567
1 do_sync_write 0,0056
58 vfs_write 0,2164
44 sys_read 0,4731
40 sys_write 0,4301
1 fput 0,0400
4 fget 0,0588
37 fget_light 0,2701
1 __set_page_buffers 0,0133
3 __clear_page_buffers 0,0246
8 __find_get_block_slow 0,0288
3 buffer_insert_list 0,0280
2 create_buffers 0,0129
1 grow_dev_page 0,0027
11 mark_buffer_dirty 0,1467
34 __brelse 0,5965
490 __find_get_block 2,2477
66 __getblk 0,8800
65 __bread 1,1404
1 set_bh_page 0,0164
2 try_to_release_page 0,0202
11 create_empty_buffers 0,0710
7 unmap_underlying_metadata 0,0753
1 __block_write_full_page 0,0011
806 __block_prepare_write 0,8723
41 __block_commit_write 0,2950
1 block_read_full_page 0,0016
8 block_prepare_write 0,1231
35 generic_commit_write 0,2288
1 submit_bh 0,0029
1 drop_buffers 0,0052
2 try_to_free_buffers 0,0106
10 alloc_buffer_head 0,1099
1 free_buffer_head 0,0101
5 init_buffer_head 0,1163
11 bio_alloc 0,0270
2 cp_new_stat64 0,0088
1 getname 0,0054
1 follow_mount 0,0072
4 do_lookup 0,0276
6 link_path_walk 0,0028
1 path_lookup 0,0032
1 poll_freewait 0,0149
2 __pollwait 0,0117
5 do_select 0,0079
1 sys_select 0,0009
1 d_alloc 0,0021
12 __d_lookup 0,0383
1 d_rehash 0,0095
1 find_inode_fast 0,0116
51 inode_times_differ 0,7391
1 update_atime 0,0050
50 inode_update_time 0,2959
52 dnotify_parent 0,3312
3 __mark_inode_dirty 0,0128
1 __writeback_single_inode 0,0057
5 mpage_writepages 0,0065
1 proc_lookup 0,0038
1 kstat_read_proc 0,0014
5 write_profile 0,0758
5 scan_bitmap_block 0,0045
2 scan_bitmap 0,0039
1 determine_prealloc_size 0,0076
12 reiserfs_allocate_blocknrs 0,0060
19 balance_leaf 0,0018
14 free_thrown 0,1346
11 do_balance 0,0421
6 do_balance_mark_leaf_dirty 0,0492
81 _make_cpu_key 0,4378
21 make_cpu_key 0,2234
1 add_to_flushlist 0,0169
77 reiserfs_get_block 0,0154
27 inode2sd 0,1812
27 update_stat_data 0,1084
132 reiserfs_update_sd 0,3048
2 lock_buffer_for_writepage 0,0139
18 reiserfs_write_full_page 0,0236
2 reiserfs_writepage 0,0351
29 reiserfs_prepare_write 0,2071
130 reiserfs_commit_write 0,3066
3 i_attrs_to_sd_attrs 0,0280
6 reiserfs_releasepage 0,0390
13 reiserfs_file_write 0,0081
1 check_right 0,0029
7 set_parameters 0,0551
4 get_lfree 0,0385
6 get_rfree 0,0606
14 get_parents 0,0352
23 ip_check_balance 0,0079
1 check_balance 0,0067
5 get_direct_parent 0,0256
3 get_virtual_node_size 0,0375
1 get_mem_for_virtual_node 0,0046
1 clear_all_dirty_bits 0,0278
72 wait_tb_buffers_until_unlocked 0,0829
10 fix_nodes 0,0093
54 unfix_nodes 0,1538
1 reiserfs_dirty_inode 0,0051
1 leaf_define_dest_src_infos 0,0024
464 leaf_paste_in_buffer 0,6563
1 internal_insert_childs 0,0021
7 decrement_counters_in_path 0,0886
7 pathrelse_and_restore 0,0897
30 pathrelse 0,5455
117 is_leaf 0,2635
78 is_internal 0,5612
114 is_tree_node 1,0962
1585 search_by_key 0,4455
13 search_for_position_by_key 0,0134
20 init_tb_struct 0,2532
5 reiserfs_paste_into_item 0,0182
1 B_IS_IN_TREE 0,0476
1 copy_short_key 0,0278
6 copy_item_head 0,1667
2 comp_short_keys 0,0247
2 decrement_bcount 0,0370
1 reiserfs_check_lock_depth 0,2000
2 push_journal_writer 0,2857
3 pop_journal_writer 0,4286
1 dump_journal_writers 0,0164
36 reiserfs_in_journal 0,0756
38 reiserfs_wait_on_write_block 0,2754
63 do_journal_begin_r 0,0969
11 journal_begin 0,2558
2 journal_prepare 0,2857
64 journal_mark_dirty 0,0872
6 journal_end 0,1395
1 remove_from_transaction 0,0027
62 check_journal_end 0,0960
12 reiserfs_update_inode_transaction 0,2264
2 reiserfs_inode_in_this_transaction 0,0476
24 reiserfs_restore_prepared_buffer 0,7742
48 reiserfs_prepare_for_journal 0,4848
37 do_journal_end 0,0128
2 sd_is_left_mergeable 0,2857
3 indirect_bytes_number 0,1304
2 indirect_is_left_mergeable 0,0172
1 cap_vm_enough_memory 0,0057
1 radix_tree_preload 0,0063
8 radix_tree_insert 0,0396
73 radix_tree_lookup 0,9481
5 radix_tree_delete 0,0224
4 number 0,0067
4 vsnprintf 0,0037
2 vsprintf 0,0465
3 atomic_dec_and_lock 0,0357
1 __const_udelay 0,0270
66 memcpy 1,2000
3 strncpy_from_user 0,0330
186 clear_user 2,6197
2 __clear_user 0,0645
2 __copy_user_intel 0,0116
4 __copy_to_user_ll 0,0385
266 __copy_from_user_ll 2,5577
28 read_zero 0,0576
1 tty_poll 0,0085
1 normal_poll 0,0031
1 add_entropy_words 0,0060
2 con_chars_in_buffer 0,2857
46 blk_rq_map_sg 0,1437
1 get_request 0,0015
67 __make_request 0,0529
12 generic_make_request 0,0271
1 submit_bio 0,0094
1 as_set_request 0,0093
2 get_stats 0,0165
98 ide_end_request 0,2961
17 ide_do_request 0,0159
6 ide_intr 0,0143
41 ide_inb 3,4167
2 ide_outb 0,1538
106 ide_outbsync 8,1538
3 ide_outsl 0,1667
18 ide_execute_command 0,1011
1 __ide_do_rw_disk 0,0005
2 ide_dma_intr 0,0108
3 ide_build_dmatable 0,0077
1 i8042_interrupt 0,0018
17 raid0_make_request 0,0471
1 sock_sendmsg 0,0057
1 sock_poll 0,0208
1 dev_seq_start 0,0075
2 unix_peer_get 0,0370
4 unix_poll 0,0265
8982 gesamt 0,0038
next prev parent reply other threads:[~2003-08-06 22:44 UTC|newest]
Thread overview: 16+ messages / expand[flat|nested] mbox.gz Atom feed top
2003-08-06 18:51 [2.6] system is very slow during disk access Michael Buesch
2003-08-06 19:29 ` Frank Van Damme
2003-08-06 19:31 ` Michael Buesch
2003-08-06 22:19 ` Willy Gardiol
2003-08-06 22:27 ` Michael Buesch
2003-08-06 19:29 ` Michael Buesch
2003-08-06 22:04 ` Andrew Morton
2003-08-06 22:44 ` Michael Buesch [this message]
2003-08-06 22:56 ` Andrew Morton
2003-08-06 23:10 ` Michael Buesch
2003-08-06 23:01 ` Bartlomiej Zolnierkiewicz
2003-08-06 23:16 ` Michael Buesch
2003-08-06 23:30 ` Bartlomiej Zolnierkiewicz
[not found] ` <200308062331.08020.insecure@mail.od.ua>
2003-08-06 20:47 ` Michael Buesch
2003-08-07 4:13 ` Nuno Silva
2003-08-07 9:53 ` Michael Buesch
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=200308070044.41198.fsdeveloper@yahoo.de \
--to=fsdeveloper@yahoo.de \
--cc=akpm@osdl.org \
--cc=gardiol@libero.it \
--cc=linux-ide@vger.kernel.org \
--cc=linux-kernel@vger.kernel.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).