From: Tilman Schmidt <tilman@imap.cc>
To: Randy Dunlap <rdunlap@xenotime.net>
Cc: Andi Kleen <ak@suse.de>, Andrew Morton <akpm@osdl.org>,
linux-kernel@vger.kernel.org, Ingo Molnar <mingo@elte.hu>,
jbeulich@novell.com
Subject: Re: [2.6.18-rc7-mm1] slow boot
Date: Fri, 29 Sep 2006 02:15:28 +0200 [thread overview]
Message-ID: <451C65A0.1080002@imap.cc> (raw)
In-Reply-To: <20060928163046.055b3ce0.rdunlap@xenotime.net>
[-- Attachment #1.1: Type: text/plain, Size: 776 bytes --]
Am 29.09.2006 01:30 schrieb Randy Dunlap:
> On Fri, 29 Sep 2006 01:20:12 +0200 Tilman Schmidt wrote:
>> Am 28.09.2006 19:12 schrieb Andi Kleen:
>>>
>>> Can you perhaps boot with profile=1 and then send readprofile output after
>>> boot?
>> I'm afraid I'll need instructions for that. I assume "profile=1"
>> is to be appended to the kernel command line; but how do I
>> retrieve that readprofile output you are asking for?
>
> Use 'readprofile'. Usage is described in
> Documentation/basic_profiling.txt in the kernel source tree.
Thanks. Result attached.
--
Tilman Schmidt E-Mail: tilman@imap.cc
Bonn, Germany
Diese Nachricht besteht zu 100% aus wiederverwerteten Bits.
Ungeoeffnet mindestens haltbar bis: (siehe Rueckseite)
[-- Attachment #1.2: readprofile.out --]
[-- Type: text/plain, Size: 20956 bytes --]
4 calibrate_delay 0.0020
59946 default_idle 525.8421
4 cpu_idle 0.0351
9 sysenter_past_esp 0.0638
1 error_code 0.0156
3 sched_clock 0.0273
1 page_is_ram 0.0088
1 pgd_alloc 0.0500
5 do_page_fault 0.0043
1 __wake_up 0.0175
2 add_preempt_count 0.0213
24 sub_preempt_count 0.2243
11 __might_sleep 0.0738
2 requeue_task 0.0455
5 task_rq_lock 0.1667
4 try_to_wake_up 0.0153
1 wake_up_process 0.0588
1 free_task 0.0278
8 __put_task_struct 0.0428
2 do_fork 0.0054
2 acquire_console_sem 0.0156
1 release_console_sem 0.0021
28 vprintk 0.0367
2 profile_hit 0.0364
2 delayed_put_task_struct 0.0645
3 do_wait 0.0012
1 sys_gettimeofday 0.0109
1 current_fs_time 0.0106
71 tasklet_action 0.6017
2 __local_bh_disable 0.0163
6212 __do_softirq 35.7011
1 local_bh_enable_ip 0.0047
89 local_bh_enable 0.3309
2 __tasklet_schedule 0.0187
1 register_proc_table 0.0042
2 lock_timer_base 0.0392
74 run_timer_softirq 0.2202
2 __mod_timer 0.0132
2 mod_timer 0.0465
4 del_timer 0.0548
3 do_gettimeofday 0.0124
1 getnstimeofday 0.0047
10 free_uid 0.0877
1 sigprocmask 0.0047
2 run_workqueue 0.0103
1 flush_cpu_workqueue 0.0071
1 worker_thread 0.0036
1 schedule_work 0.0588
6 put_pid 0.1714
1 delayed_put_pid 0.0769
1 alloc_pid 0.0019
29 rcu_start_batch 0.6444
2 rcu_init_percpu_data 0.0238
95 __rcu_process_callbacks 0.2707
17 rcu_process_callbacks 0.4857
1 call_rcu_bh 0.0094
1 sys_clock_gettime 0.0076
1 kthread_should_stop 0.0385
2 __wake_up_bit 0.0408
1 wake_bit_function 0.0149
1 init_waitqueue_head 0.0303
2 remove_wait_queue 0.0351
2 add_wait_queue 0.0377
179 hrtimer_run_queues 0.6047
1 hrtimer_cancel 0.0417
2 sys_nanosleep 0.0235
1 down_write_trylock 0.0200
1 down_read 0.0169
1 debug_mutex_free_waiter 0.0152
1 lockdep_init_map 0.0061
8 debug_check_no_locks_freed 0.0282
23 lock_release 0.0821
996 lock_acquire 9.1376
1 drop_key_refs 0.0227
1 get_futex_key 0.0045
3 do_futex 0.0009
1 sys_futex 0.0041
12 lookup_symbol 0.2353
1 page_waitqueue 0.0222
1 find_get_page 0.0161
1 sys_fadvise64_64 0.0023
2 __free_pages_ok 0.0069
22 get_page_from_freelist 0.0263
1 __alloc_pages 0.0016
3 free_hot_cold_page 0.0098
2 wb_kupdate 0.0096
1 test_clear_page_writeback 0.0056
1 test_set_page_writeback 0.0045
1 generic_writepages 0.0015
1 force_page_cache_readahead 0.0090
1 release_pages 0.0030
1 __pagevec_lru_add 0.0053
1 lru_add_drain 0.0115
1 mark_page_accessed 0.0200
1 put_page 0.0182
1 vma_prio_tree_insert 0.0227
1 vm_normal_page 0.0115
3 unmap_vmas 0.0027
4 do_wp_page 0.0049
1 copy_page_range 0.0014
1 __handle_mm_fault 0.0006
3 find_vma 0.0353
1 __vm_enough_memory 0.0046
1 vma_adjust 0.0013
1 do_munmap 0.0023
2 do_mmap_pgoff 0.0013
1 page_remove_rmap 0.0143
4 __remove_vm_area 0.0769
4 check_irq_on 0.2000
7 kmem_flagcheck 0.1795
1 kmem_cache_name 0.1250
1 dbg_redzone1 0.0357
18 poison_obj 0.4091
401 check_poison_obj 1.1392
28 drain_array 0.1667
1 cache_flusharray 0.0044
74 kfree 0.3834
458 kmem_cache_free 2.5730
2 kmem_rcu_free 0.0500
4 drain_freelist 0.0263
53 cache_reap 0.2409
7 cache_alloc_debugcheck_after 0.0219
44 kmem_cache_alloc 0.2716
35 cache_alloc_refill 0.0233
1 __kmalloc_track_caller 0.0046
3 kmem_cache_zalloc 0.0152
15 __kmalloc 0.0685
4 sys_faccessat 0.0131
2 sys_access 0.1111
1 __dentry_open 0.0019
1 do_sys_open 0.0055
1 sys_write 0.0104
10 file_free_rcu 0.5882
2 get_max_files 0.2000
11 fget_light 0.0663
3 sync_supers 0.0152
1 sys_readlinkat 0.0068
3 generic_fillattr 0.0164
1 vfs_getattr 0.0059
1 vfs_lstat 0.0526
2 pipe_readv 0.0025
4 getname 0.0217
1 permission 0.0051
2 __follow_mount 0.0192
3 do_lookup 0.0097
6 __link_path_walk 0.0018
2 link_path_walk 0.0101
2 do_path_lookup 0.0032
5 __user_walk_fd 0.0769
4 poll_freewait 0.0444
1 __pollwait 0.0055
43 do_select 0.0341
22 core_sys_select 0.0298
10 sys_select 0.0306
11 do_sys_poll 0.0109
3 sys_poll 0.0435
7 d_callback 0.1795
1 _d_rehash 0.0156
1 __d_path 0.0029
5 __d_lookup 0.0187
1 alloc_inode 0.0024
1 file_update_time 0.0076
1 is_bad_inode 0.0455
5 free_fdtable_rcu 0.0198
1 sync_sb_inodes 0.0016
1 unlock_buffer 0.0526
2 alloc_buffer_head 0.0260
4 __find_get_block_slow 0.0145
1 ll_rw_block 0.0055
6 __find_get_block 0.0134
2 __getblk 0.0037
2 __block_write_full_page 0.0026
1 block_write_full_page 0.0048
1 bio_init 0.0094
1 init_once 0.0084
2 do_mpage_readpage 0.0013
1 inotify_d_instantiate 0.0098
1 proc_readfd 0.0019
1 sysfs_get_name 0.0149
1 sysfs_release 0.0066
2 sysfs_lookup 0.0045
1 sysfs_create_link 0.0032
1 reiserfs_discard_all_prealloc 0.0167
1 search_by_entry_key 0.0017
1 reiserfs_lookup 0.0039
2 _get_block_create_0 0.0013
1 reiserfs_read_locked_inode 0.0008
1 reiserfs_commit_page 0.0023
10 reiserfs_readdir 0.0088
2 load_bitmap_info_data 0.0145
2 comp_items 0.0317
1 decrement_counters_in_path 0.0147
25 search_by_key 0.0064
1 flush_commit_list 0.0007
4 do_journal_end 0.0014
2 do_journal_begin_r 0.0031
1 journal_begin 0.0043
1 journal_end_sync 0.0093
1 reiserfs_commit_for_inode 0.0026
1 direntry_create_vi 0.0030
2 reiserfs_permission 0.0556
1 dummy_inode_alloc_security 0.1429
1 dummy_task_free_security 0.2000
2 dummy_vm_enough_memory 0.0625
1 init_request_from_bio 0.0076
3 _atomic_dec_and_lock 0.0625
1 prio_tree_replace 0.0110
2 prio_tree_insert 0.0040
1 radix_tree_preload 0.0071
6 memcmp 0.1429
3 number 0.0059
106 delay_tsc 4.6087
15 read_current_timer 0.5357
1 __delay 0.0909
3 memcpy 0.0698
7 strncpy_from_user 0.0875
1 __copy_from_user_ll 0.0045
3 copy_from_user 0.0278
18 __copy_to_user_ll 0.0811
4 copy_to_user 0.0488
1 irqsafe2A_spin_12 0.0066
1 irqsafe2A_wlock_12 0.0066
1 irqsafe2A_rlock_12 0.0066
1 irqsafe2A_spin_21 0.0066
1 irqsafe2A_wlock_21 0.0066
1 irqsafe2A_rlock_21 0.0066
19 dotest 0.0206
1 irqsafe1_hard_spin_12 0.0067
1 irqsafe1_hard_wlock_12 0.0067
1 irqsafe1_hard_rlock_12 0.0067
1 irqsafe1_hard_wlock_21 0.0067
1 irqsafe1_hard_rlock_21 0.0067
2 irqsafe2B_hard_spin_12 0.0123
1 irqsafe2B_hard_wlock_12 0.0062
1 irqsafe2B_hard_rlock_12 0.0062
1 irqsafe2B_hard_spin_21 0.0062
2 irqsafe2B_hard_wlock_21 0.0123
2 irqsafe2B_hard_rlock_21 0.0123
1 irqsafe3_hard_spin_123 0.0053
1 irqsafe3_hard_wlock_123 0.0053
1 irqsafe3_hard_rlock_123 0.0053
2 irqsafe3_hard_spin_132 0.0105
1 irqsafe3_hard_wlock_132 0.0053
1 irqsafe3_hard_rlock_132 0.0053
1 irqsafe3_hard_wlock_213 0.0053
1 irqsafe3_hard_rlock_213 0.0053
2 irqsafe3_hard_spin_231 0.0105
1 irqsafe3_hard_wlock_231 0.0053
1 irqsafe3_hard_rlock_231 0.0053
1 irqsafe3_hard_spin_312 0.0053
1 irqsafe3_hard_wlock_312 0.0053
1 irqsafe3_hard_rlock_312 0.0053
1 irqsafe3_hard_spin_321 0.0053
1 irqsafe3_hard_wlock_321 0.0053
1 irqsafe3_hard_rlock_321 0.0053
1 irqsafe4_hard_spin_123 0.0050
2 irqsafe4_hard_wlock_123 0.0099
2 irqsafe4_hard_rlock_123 0.0099
2 irqsafe4_hard_spin_132 0.0099
1 irqsafe4_hard_wlock_132 0.0050
1 irqsafe4_hard_rlock_132 0.0050
1 irqsafe4_hard_wlock_213 0.0050
1 irqsafe4_hard_rlock_213 0.0050
1 irqsafe4_hard_spin_231 0.0050
1 irqsafe4_hard_wlock_231 0.0050
1 irqsafe4_hard_rlock_231 0.0050
2 irqsafe4_hard_spin_312 0.0099
1 irqsafe4_hard_wlock_312 0.0050
1 irqsafe4_hard_rlock_312 0.0050
1 irqsafe4_hard_spin_321 0.0050
1 irqsafe4_hard_wlock_321 0.0050
1 irqsafe4_hard_rlock_321 0.0050
1 irq_inversion_hard_spin_123 0.0050
2 irq_inversion_hard_wlock_123 0.0099
2 irq_inversion_hard_rlock_123 0.0099
2 irq_inversion_hard_spin_132 0.0099
1 irq_inversion_hard_wlock_132 0.0050
1 irq_inversion_hard_rlock_132 0.0050
1 irq_inversion_hard_wlock_213 0.0050
1 irq_inversion_hard_rlock_213 0.0050
1 irq_inversion_hard_spin_231 0.0050
1 irq_inversion_hard_wlock_231 0.0050
1 irq_inversion_hard_rlock_231 0.0050
2 irq_inversion_hard_spin_312 0.0099
1 irq_inversion_hard_wlock_312 0.0050
1 irq_inversion_hard_rlock_312 0.0050
1 irq_inversion_hard_spin_321 0.0050
1 irq_inversion_hard_wlock_321 0.0050
1 irq_inversion_hard_rlock_321 0.0050
1 irq_read_recursion_hard_123 0.0050
2 irq_read_recursion_hard_132 0.0099
1 irq_read_recursion_hard_231 0.0050
2 irq_read_recursion_hard_312 0.0099
1 irq_read_recursion_hard_321 0.0050
2 __spin_lock_init 0.0200
5 _raw_spin_unlock 0.0455
1 _raw_read_lock 0.0417
4 _raw_spin_lock 0.0175
3 fb_get_color_depth 0.0517
1 vgacon_save_screen 0.0105
5 cursor_timer_handler 0.1163
14 fb_flashcursor 0.0220
1 fbcon_cursor 0.0016
13 bit_cursor 0.0117
7 bit_putcs 0.0063
20 bitfill_aligned 0.1010
9 cfb_copyarea 0.0042
56 cfb_imageblit 0.0399
1 acpi_os_signal_semaphore 0.0099
1 acpi_ns_lookup 0.0007
2 acpi_tb_sum_table 0.0417
2 acpi_tb_validate_rsdp 0.0189
1 scrup 0.0053
1 con_chars_in_buffer 0.1429
2 do_con_write 0.0004
2 intel_i810_configure 0.0074
12 i810_write_dac 0.2553
62 i810_read_dac 1.3478
26 i810fb_getcolreg 0.0956
3 i810_screen_off 0.0349
4 i810_enable_cursor 0.1333
983 i810fb_cursor 1.4413
4 vortex_timer 0.0049
14 ide_inb 1.2727
2 ide_outb 0.3333
2 ide_driveid_update 0.0051
2 try_to_identify 0.0019
1 probe_hwif 0.0006
1 usb_hcd_poll_rh_status 0.0029
1 rh_timer_func 0.1000
2 usb_hcd_submit_urb 0.0010
13 i8042_interrupt 0.0260
4 i8042_timer_func 0.2500
1 sock_poll 0.0476
1 sock_wfree 0.0172
1 datagram_poll 0.0045
1 udp_poll 0.0055
5 unix_poll 0.0278
1 cache_clean 0.0025
46 schedule 0.0338
3 preempt_schedule 0.0361
2 cond_resched 0.0408
3 schedule_timeout 0.0197
2 __mutex_unlock_slowpath 0.0080
1 mutex_unlock 0.1000
9 __mutex_lock_interruptible_slowpath 0.0143
148 __mutex_lock_slowpath 0.2814
11 mutex_lock_nested 0.0202
6 _spin_lock 0.1200
26 _write_unlock_irq 0.3881
5 _spin_lock_irq 0.0893
2 _spin_lock_irqsave 0.0333
6 _spin_unlock 0.0984
605 _spin_unlock_irqrestore 6.7978
700 _spin_unlock_irq 10.4478
2 _read_unlock_irqrestore 0.0225
19 _read_unlock_irq 0.2836
12 _write_unlock_irqrestore 0.1348
1 unlock_kernel 0.0179
1 __release_kernel_lock 0.0417
46 *unknown*
72643 total 0.0308
[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 253 bytes --]
next prev parent reply other threads:[~2006-09-29 0:13 UTC|newest]
Thread overview: 22+ messages / expand[flat|nested] mbox.gz Atom feed top
2006-09-24 16:59 [2.6.18-rc7-mm1] slow boot Tilman Schmidt
2006-09-24 19:22 ` Valdis.Kletnieks
2006-09-24 22:02 ` Tilman Schmidt
2006-09-24 21:53 ` Andrew Morton
2006-09-24 22:15 ` Tilman Schmidt
2006-09-24 22:36 ` Alan Cox
2006-09-24 22:41 ` Andrew Morton
2006-09-26 23:48 ` Tilman Schmidt
2006-09-27 0:21 ` Andrew Morton
2006-09-28 17:00 ` Tilman Schmidt
2006-09-28 17:12 ` Andi Kleen
2006-09-28 23:20 ` Tilman Schmidt
2006-09-28 23:30 ` Randy Dunlap
2006-09-29 0:15 ` Tilman Schmidt [this message]
2006-09-29 7:10 ` Jan Beulich
2006-09-29 16:12 ` Andi Kleen
2006-09-29 18:39 ` Ingo Molnar
2006-10-04 7:05 ` Jan Beulich
2006-09-29 8:49 ` Andi Kleen
2006-09-24 21:58 ` [2.6.18-mm1] slow boot (was: [2.6.18-rc7-mm1] slow boot) Tilman Schmidt
2006-09-25 12:09 ` [2.6.18-rc7-mm1] slow boot Alexander Gran
2006-10-25 18:14 ` Tilman Schmidt
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=451C65A0.1080002@imap.cc \
--to=tilman@imap.cc \
--cc=ak@suse.de \
--cc=akpm@osdl.org \
--cc=jbeulich@novell.com \
--cc=linux-kernel@vger.kernel.org \
--cc=mingo@elte.hu \
--cc=rdunlap@xenotime.net \
/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 an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.