Hi Roland!
I made tracing for srpt_add_one function. Trace log attached to mail
Roland Dreier писал 2012-04-11 02:09:
On Tue, Apr 10, 2012 at 7:52 AM, Alexey Shvetsov <ale...@gentoo.org>
wrote:
I'm trying to use ib_srpt from mainline kernel (3.3.x and 3.4-rcX)
But right after loading ib_srpt i always get error in dmesg
srpt_add_one(mthca0) failed.
I would suggest the following: make sure ib_mthca is NOT loaded, and
load
the srpt module. Then enable ftrace -- config options
CONFIG_FUNCTION_TRACER
CONFIG_DYNAMIC_FTRACE
CONFIG_FUNCTION_GRAPH_TRACER
and use the function graph tracer to see what srpt_add_one() calls:
# cd /sys/kernel/debug/trace
# echo srpt_add_one > set_graph_function
# echo function_graph > current_tracer
# modprobe ib_mthca
# cat trace
and send the output of that "cat trace" command to the list. Then we
can
see what step of initialization fails and debug from there.
(cf the section "the function_graph tracer" in
https://lwn.net/Articles/370423/)
Thanks!
- R.
--
Best Regards,
Alexey 'Alexxy' Shvetsov
Petersburg Nuclear Physics Institute, Russia
Department of Molecular and Radiation Biophysics
Gentoo Team Ru
Gentoo Linux Dev
mailto:alexx...@gmail.com
mailto:ale...@gentoo.org
mailto:ale...@omrb.pnpi.spb.ru
# tracer: function_graph
#
# CPU DURATION FUNCTION CALLS
# | | | | | | |
0) | srpt_add_one() {
0) 3.219 us | kmem_cache_alloc_trace();
0) 0.135 us | __init_waitqueue_head();
0) | ib_query_device() {
0) 0.214 us | kmem_cache_alloc_trace();
0) 0.176 us | kmem_cache_alloc_trace();
0) 0.175 us | kmem_cache_alloc_trace();
0) | dma_pool_alloc() {
0) 0.256 us | _raw_spin_lock_irqsave();
0) 0.158 us | _raw_spin_unlock_irqrestore();
0) 2.247 us | }
0) 0.167 us | kmem_cache_alloc_trace();
0) | dma_pool_alloc() {
0) 0.180 us | _raw_spin_lock_irqsave();
0) 0.157 us | _raw_spin_unlock_irqrestore();
0) 2.358 us | }
0) | down() {
0) 0.176 us | _raw_spin_lock_irqsave();
0) 0.151 us | _raw_spin_unlock_irqrestore();
0) 2.080 us | }
0) 0.150 us | _raw_spin_lock();
0) 0.136 us | __init_waitqueue_head();
0) | mutex_lock() {
0) 0.373 us | __mutex_lock_slowpath();
0) 1.295 us | }
0) | mutex_unlock() {
0) 0.191 us | __mutex_unlock_slowpath();
0) 1.117 us | }
0) | wait_for_completion_timeout() {
0) | wait_for_common() {
0) 0.244 us | _raw_spin_lock_irq();
0) | schedule_timeout() {
0) 0.140 us | init_timer_key();
0) | lock_timer_base.clone.24() {
0) 0.260 us | _raw_spin_lock_irqsave();
0) 1.159 us | }
0) 0.136 us | idle_cpu();
0) 0.145 us | internal_add_timer();
0) 0.144 us | _raw_spin_unlock_irqrestore();
0) | schedule() {
0) | __schedule() {
0) 0.322 us | rcu_note_context_switch();
0) 0.164 us | _raw_spin_lock_irq();
0) | deactivate_task() {
0) | dequeue_task() {
0) 0.534 us | update_rq_clock();
0) | dequeue_task_fair() {
0) | dequeue_entity() {
0) | update_curr() {
0) 0.198 us | cpuacct_charge();
0) 1.407 us | }
0) 0.137 us | clear_buddies();
0) 0.137 us | update_cfs_load();
0) 0.191 us | update_cfs_shares();
0) 5.495 us | }
0) 0.136 us | hrtick_update();
0) 7.381 us | }
0) 9.681 us | }
0) + 11.686 us | }
0) 0.146 us | idle_balance();
0) 0.144 us | put_prev_task_fair();
0) 0.157 us | pick_next_task_fair();
0) 0.196 us | pick_next_task_stop();
0) 0.222 us | pick_next_task_rt();
0) 0.158 us | pick_next_task_fair();
0) | pick_next_task_idle() {
0) 0.141 us | calc_load_account_idle();
0) 1.112 us | }
0) 0.254 us | finish_task_switch();
0) + 95.055 us | }
0) + 96.075 us | }
0) | del_timer_sync() {
0) | try_to_del_timer_sync() {
0) | lock_timer_base.clone.24() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 1.169 us | }
0) 0.150 us | _raw_spin_unlock_irqrestore();
0) 3.040 us | }
0) 3.964 us | }
0) ! 107.618 us | }
0) 0.153 us | _raw_spin_lock_irq();
0) ! 110.742 us | }
0) ! 111.653 us | }
0) 0.170 us | _raw_spin_lock();
0) | up() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 0.146 us | _raw_spin_unlock_irqrestore();
0) 1.986 us | }
0) | dma_pool_free() {
0) 0.162 us | _raw_spin_lock_irqsave();
0) 0.146 us | _raw_spin_unlock_irqrestore();
0) 1.968 us | }
0) | kfree() {
0) 0.149 us | __phys_addr();
0) 1.209 us | }
0) | dma_pool_free() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 0.144 us | _raw_spin_unlock_irqrestore();
0) 2.016 us | }
0) | kfree() {
0) 0.137 us | __phys_addr();
0) 1.115 us | }
0) | kfree() {
0) 0.141 us | __phys_addr();
0) 1.104 us | }
0) | kfree() {
0) 0.136 us | __phys_addr();
0) 1.063 us | }
0) ! 151.080 us | }
0) | ib_alloc_pd() {
0) 0.223 us | kmem_cache_alloc_trace();
0) 0.180 us | _raw_spin_lock_irqsave();
0) 0.144 us | _raw_spin_unlock_irqrestore();
0) 0.159 us | _raw_spin_lock_irqsave();
0) 0.148 us | _raw_spin_unlock_irqrestore();
0) 0.162 us | kmem_cache_alloc_trace();
0) | dma_pool_alloc() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 0.144 us | _raw_spin_unlock_irqrestore();
0) 1.943 us | }
0) | down() {
0) 0.161 us | _raw_spin_lock_irqsave();
0) 0.147 us | _raw_spin_unlock_irqrestore();
0) 1.958 us | }
0) 0.149 us | _raw_spin_lock();
0) 0.136 us | __init_waitqueue_head();
0) | mutex_lock() {
0) 0.373 us | __mutex_lock_slowpath();
0) 1.354 us | }
0) | mutex_unlock() {
0) 0.205 us | __mutex_unlock_slowpath();
0) 1.100 us | }
0) | wait_for_completion_timeout() {
0) | wait_for_common() {
0) 0.158 us | _raw_spin_lock_irq();
0) | schedule_timeout() {
0) 0.140 us | init_timer_key();
0) | lock_timer_base.clone.24() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 1.065 us | }
0) 0.140 us | idle_cpu();
0) 0.182 us | internal_add_timer();
0) 0.144 us | _raw_spin_unlock_irqrestore();
0) | schedule() {
0) | __schedule() {
0) 0.321 us | rcu_note_context_switch();
0) 0.160 us | _raw_spin_lock_irq();
0) | deactivate_task() {
0) | dequeue_task() {
0) 0.406 us | update_rq_clock();
0) | dequeue_task_fair() {
0) | dequeue_entity() {
0) | update_curr() {
0) 0.175 us | cpuacct_charge();
0) 1.336 us | }
0) 0.137 us | clear_buddies();
0) 0.136 us | update_cfs_load();
0) 0.175 us | update_cfs_shares();
0) 5.072 us | }
0) 0.134 us | hrtick_update();
0) 7.063 us | }
0) 9.485 us | }
0) + 10.460 us | }
0) 0.141 us | idle_balance();
0) 0.140 us | put_prev_task_fair();
0) 0.154 us | pick_next_task_fair();
0) 0.137 us | pick_next_task_stop();
0) 0.199 us | pick_next_task_rt();
0) 0.153 us | pick_next_task_fair();
0) | pick_next_task_idle() {
0) 0.151 us | calc_load_account_idle();
0) 1.751 us | }
0) 0.248 us | finish_task_switch();
0) + 31.935 us | }
0) + 32.899 us | }
0) | del_timer_sync() {
0) | try_to_del_timer_sync() {
0) | lock_timer_base.clone.24() {
0) 0.159 us | _raw_spin_lock_irqsave();
0) 1.083 us | }
0) 0.143 us | _raw_spin_unlock_irqrestore();
0) 2.910 us | }
0) 3.836 us | }
0) + 43.888 us | }
0) 0.266 us | _raw_spin_lock_irq();
0) + 46.750 us | }
0) + 47.629 us | }
0) 0.151 us | _raw_spin_lock();
0) | up() {
0) 0.162 us | _raw_spin_lock_irqsave();
0) 0.147 us | _raw_spin_unlock_irqrestore();
0) 1.944 us | }
0) | dma_pool_free() {
0) 0.171 us | _raw_spin_lock_irqsave();
0) 0.145 us | _raw_spin_unlock_irqrestore();
0) 1.962 us | }
0) | kfree() {
0) 0.137 us | __phys_addr();
0) 1.074 us | }
0) + 76.640 us | }
0) | ib_get_dma_mr() {
0) 0.179 us | kmem_cache_alloc_trace();
0) 0.187 us | _raw_spin_lock_irqsave();
0) 0.145 us | _raw_spin_unlock_irqrestore();
0) 0.160 us | kmem_cache_alloc_trace();
0) | dma_pool_alloc() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 0.145 us | _raw_spin_unlock_irqrestore();
0) 1.947 us | }
0) | down() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 0.146 us | _raw_spin_unlock_irqrestore();
0) 1.977 us | }
0) 0.153 us | _raw_spin_lock();
0) 0.136 us | __init_waitqueue_head();
0) | mutex_lock() {
0) 0.377 us | __mutex_lock_slowpath();
0) 1.260 us | }
0) | mutex_unlock() {
0) 0.210 us | __mutex_unlock_slowpath();
0) 1.106 us | }
0) | wait_for_completion_timeout() {
0) | wait_for_common() {
0) 0.171 us | _raw_spin_lock_irq();
0) | schedule_timeout() {
0) 0.140 us | init_timer_key();
0) | lock_timer_base.clone.24() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 1.039 us | }
0) 0.138 us | idle_cpu();
0) 0.148 us | internal_add_timer();
0) 0.144 us | _raw_spin_unlock_irqrestore();
0) | schedule() {
0) | __schedule() {
0) 0.146 us | rcu_note_context_switch();
0) 0.159 us | _raw_spin_lock_irq();
0) | deactivate_task() {
0) | dequeue_task() {
0) 0.471 us | update_rq_clock();
0) | dequeue_task_fair() {
0) | dequeue_entity() {
0) | update_curr() {
0) 0.168 us | cpuacct_charge();
0) 1.305 us | }
0) 0.137 us | clear_buddies();
0) 0.137 us | update_cfs_load();
0) 0.173 us | update_cfs_shares();
0) 5.052 us | }
0) 0.135 us | hrtick_update();
0) 6.941 us | }
0) 9.390 us | }
0) + 10.303 us | }
0) 0.140 us | idle_balance();
0) 0.141 us | put_prev_task_fair();
0) 0.137 us | pick_next_task_fair();
0) 0.136 us | pick_next_task_stop();
0) 0.218 us | pick_next_task_rt();
0) 0.137 us | pick_next_task_fair();
0) | pick_next_task_idle() {
0) 0.134 us | calc_load_account_idle();
0) 1.025 us | }
0) 0.248 us | finish_task_switch();
0) + 29.669 us | }
0) + 30.600 us | }
0) | del_timer_sync() {
0) | try_to_del_timer_sync() {
0) | lock_timer_base.clone.24() {
0) 0.158 us | _raw_spin_lock_irqsave();
0) 1.046 us | }
0) 0.148 us | _raw_spin_unlock_irqrestore();
0) 2.876 us | }
0) 3.772 us | }
0) + 42.243 us | }
0) 0.279 us | _raw_spin_lock_irq();
0) + 45.244 us | }
0) + 50.200 us | }
0) 0.150 us | _raw_spin_lock();
0) | up() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 0.144 us | _raw_spin_unlock_irqrestore();
0) 1.995 us | }
0) | dma_pool_free() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 0.145 us | _raw_spin_unlock_irqrestore();
0) 1.980 us | }
0) | kfree() {
0) 0.137 us | __phys_addr();
0) 1.189 us | }
0) + 76.919 us | }
0) 0.288 us | ib_create_srq();
0) | ib_dereg_mr() {
0) | down() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 0.146 us | _raw_spin_unlock_irqrestore();
0) 2.057 us | }
0) 0.150 us | _raw_spin_lock();
0) 0.136 us | __init_waitqueue_head();
0) | mutex_lock() {
0) 0.385 us | __mutex_lock_slowpath();
0) 1.275 us | }
0) | mutex_unlock() {
0) 0.191 us | __mutex_unlock_slowpath();
0) 1.067 us | }
0) | wait_for_completion_timeout() {
0) | wait_for_common() {
0) 0.155 us | _raw_spin_lock_irq();
0) | schedule_timeout() {
0) 0.155 us | init_timer_key();
0) | lock_timer_base.clone.24() {
0) 0.166 us | _raw_spin_lock_irqsave();
0) 1.079 us | }
0) 0.147 us | idle_cpu();
0) 0.146 us | internal_add_timer();
0) 0.146 us | _raw_spin_unlock_irqrestore();
0) | schedule() {
0) | __schedule() {
0) 0.142 us | rcu_note_context_switch();
0) 0.173 us | _raw_spin_lock_irq();
0) | deactivate_task() {
0) | dequeue_task() {
0) 0.415 us | update_rq_clock();
0) | dequeue_task_fair() {
0) | dequeue_entity() {
0) | update_curr() {
0) 0.182 us | cpuacct_charge();
0) 1.239 us | }
0) 0.139 us | clear_buddies();
0) 0.136 us | update_cfs_load();
0) 0.181 us | update_cfs_shares();
0) 4.969 us | }
0) 0.143 us | hrtick_update();
0) 6.772 us | }
0) 8.866 us | }
0) 9.797 us | }
0) 0.151 us | idle_balance();
0) 0.141 us | put_prev_task_fair();
0) 0.137 us | pick_next_task_fair();
0) 0.143 us | pick_next_task_stop();
0) 0.200 us | pick_next_task_rt();
0) 0.138 us | pick_next_task_fair();
0) | pick_next_task_idle() {
0) 0.134 us | calc_load_account_idle();
0) 1.013 us | }
0) 0.248 us | finish_task_switch();
0) + 32.126 us | }
0) + 33.167 us | }
0) | del_timer_sync() {
0) | try_to_del_timer_sync() {
0) | lock_timer_base.clone.24() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 1.045 us | }
0) 0.144 us | _raw_spin_unlock_irqrestore();
0) 2.946 us | }
0) 3.860 us | }
0) + 44.368 us | }
0) 0.157 us | _raw_spin_lock_irq();
0) + 47.295 us | }
0) + 48.185 us | }
0) 0.151 us | _raw_spin_lock();
0) | up() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 0.144 us | _raw_spin_unlock_irqrestore();
0) 1.954 us | }
0) 0.257 us | _raw_spin_lock_irqsave();
0) 0.149 us | _raw_spin_unlock_irqrestore();
0) | kfree() {
0) 0.136 us | __phys_addr();
0) 1.079 us | }
0) + 68.258 us | }
0) | ib_dealloc_pd() {
0) | down() {
0) 0.162 us | _raw_spin_lock_irqsave();
0) 0.144 us | _raw_spin_unlock_irqrestore();
0) 1.966 us | }
0) 0.162 us | _raw_spin_lock();
0) 0.136 us | __init_waitqueue_head();
0) | mutex_lock() {
0) 0.372 us | __mutex_lock_slowpath();
0) 1.271 us | }
0) | mutex_unlock() {
0) 0.191 us | __mutex_unlock_slowpath();
0) 1.103 us | }
0) | wait_for_completion_timeout() {
0) | wait_for_common() {
0) 0.153 us | _raw_spin_lock_irq();
0) | schedule_timeout() {
0) 0.139 us | init_timer_key();
0) | lock_timer_base.clone.24() {
0) 0.174 us | _raw_spin_lock_irqsave();
0) 1.141 us | }
0) 0.137 us | idle_cpu();
0) 0.147 us | internal_add_timer();
0) 0.146 us | _raw_spin_unlock_irqrestore();
0) | schedule() {
0) | __schedule() {
0) 0.142 us | rcu_note_context_switch();
0) 0.160 us | _raw_spin_lock_irq();
0) | deactivate_task() {
0) | dequeue_task() {
0) 0.464 us | update_rq_clock();
0) | dequeue_task_fair() {
0) | dequeue_entity() {
0) | update_curr() {
0) 0.206 us | cpuacct_charge();
0) 1.917 us | }
0) 0.137 us | clear_buddies();
0) 0.136 us | update_cfs_load();
0) 0.188 us | update_cfs_shares();
0) 5.753 us | }
0) 0.135 us | hrtick_update();
0) 7.640 us | }
0) 9.792 us | }
0) + 10.729 us | }
0) 0.140 us | idle_balance();
0) 0.139 us | put_prev_task_fair();
0) 0.138 us | pick_next_task_fair();
0) 0.136 us | pick_next_task_stop();
0) 0.211 us | pick_next_task_rt();
0) 0.155 us | pick_next_task_fair();
0) | pick_next_task_idle() {
0) 0.133 us | calc_load_account_idle();
0) 1.030 us | }
0) 0.254 us | finish_task_switch();
0) + 35.498 us | }
0) + 36.438 us | }
0) | del_timer_sync() {
0) | try_to_del_timer_sync() {
0) | lock_timer_base.clone.24() {
0) 0.161 us | _raw_spin_lock_irqsave();
0) 1.088 us | }
0) 0.143 us | _raw_spin_unlock_irqrestore();
0) 2.890 us | }
0) 3.802 us | }
0) + 47.628 us | }
0) 0.275 us | _raw_spin_lock_irq();
0) + 50.627 us | }
0) + 51.515 us | }
0) 0.149 us | _raw_spin_lock();
0) | up() {
0) 0.160 us | _raw_spin_lock_irqsave();
0) 0.145 us | _raw_spin_unlock_irqrestore();
0) 1.975 us | }
0) 0.161 us | _raw_spin_lock_irqsave();
0) 0.150 us | _raw_spin_unlock_irqrestore();
0) 0.158 us | _raw_spin_lock_irqsave();
0) 0.144 us | _raw_spin_unlock_irqrestore();
0) | kfree() {
0) 0.136 us | __phys_addr();
0) 1.075 us | }
0) + 72.605 us | }
0) | kfree() {
0) 0.137 us | __phys_addr();
0) 1.106 us | }
0) | printk() {
0) | vprintk() {
0) 0.273 us | _raw_spin_lock();
0) 0.346 us | log_prefix();
0) 0.269 us | emit_log_char();
0) 0.173 us | emit_log_char();
0) 0.144 us | emit_log_char();
0) 0.145 us | emit_log_char();
0) 0.147 us | emit_log_char();
0) 0.144 us | emit_log_char();
0) 0.144 us | emit_log_char();
0) 0.145 us | emit_log_char();
0) 0.145 us | emit_log_char();
0) 0.143 us | emit_log_char();
0) 0.150 us | emit_log_char();
0) 0.146 us | emit_log_char();
0) 0.145 us | emit_log_char();
0) 0.145 us | emit_log_char();
0) 0.145 us | emit_log_char();
0) 0.145 us | emit_log_char();
0) 0.160 us | emit_log_char();
0) 0.178 us | emit_log_char();
0) 0.144 us | emit_log_char();
0) 0.143 us | emit_log_char();
0) 0.143 us | emit_log_char();
0) 0.143 us | emit_log_char();
0) 0.143 us | emit_log_char();
0) 0.145 us | emit_log_char();
0) 0.143 us | emit_log_char();
0) 0.144 us | emit_log_char();
0) 0.144 us | emit_log_char();
0) 0.144 us | emit_log_char();
0) 0.146 us | emit_log_char();
0) 0.144 us | emit_log_char();
0) 0.144 us | emit_log_char();
0) 0.150 us | emit_log_char();
0) | console_trylock() {
0) | down_trylock() {
0) 0.228 us | _raw_spin_lock_irqsave();
0) 0.151 us | _raw_spin_unlock_irqrestore();
0) 2.053 us | }
0) 3.154 us | }
0) | console_unlock() {
0) 0.260 us | _raw_spin_lock_irqsave();
0) 0.163 us | log_prefix();
0) 0.173 us | _call_console_drivers();
0) 0.171 us | _call_console_drivers();
0) 0.171 us | _raw_spin_lock_irqsave();
0) | up() {
0) 0.158 us | _raw_spin_lock_irqsave();
0) 0.147 us | _raw_spin_unlock_irqrestore();
0) 2.578 us | }
0) 0.150 us | _raw_spin_lock();
0) 0.154 us | _raw_spin_unlock_irqrestore();
0) + 10.567 us | }
0) + 50.298 us | }
0) + 51.389 us | }
0) | ib_set_client_data() {
0) 0.178 us | _raw_spin_lock_irqsave();
0) 0.155 us | _raw_spin_unlock_irqrestore();
0) 2.163 us | }
0) ! 514.352 us | }
