Call Traceとは

スポンサーリンク

Call Traceとは、Linux Kernelの呼び出した関数のスタックトレースです。OS(Kernel)がハングアップした場合などでログに出力されます。

スタックトレースとは、関数がどのようにスタックされていったのか(どの関数がどの関数を呼び出したか)を示したものです。

スタックとは、LIFO(Last IN First OUT)のデータ格納方式のことです。プログラムにおいては、例えばプログラム内の関数Aから別の関数Bを呼び出し、関数Bの仕事が終わった後に関数Aに戻るためのメモリアドレスを格納する方式のことです。スタックを格納するメモリ領域をスタック領域と言います。

スポンサーリンク
スポンサーリンク

プログラム実行中のCPU、メモリの変化

プログラムMain関数から始まり、様々な関数を次々に呼び出すことができます。上図のようにメモリ上に展開されたプログラムAはメモリアドレス100から実行するために、CPUのプログラムカウンタというRegisterの初期値を100にセットします。

100の"命令1"が終わると次は101を実行します。それが終わると102へ、、、と順に命令を実行していきます。

しかし途中で関数を呼び出し(Call)すると、実行する命令はその関数が展開されているメモリアドレスへ飛びます。上記例では、105の次は関数Aの最初のメモリアドレスである200へ飛びます。しかしただ飛んでは戻ってこれなくなるのでスタック領域に関数Aが終わった後に戻るべきメモリアドレス「106」を格納します。

そして関数Aに飛び、同様に命令を実行していきますが、途中でまた同様に関数Bへ飛びます。そして同じようにスタック領域に戻るべきメモリアドレス「203」を格納します。このときスタック領域には203と106が格納されています

そして関数Bが終わるとスタック領域から戻るべきメモリアドレスを取得するのですが、このときにLIFOに従い最後に格納した「203」へ戻り、スタック領域から「203」を削除します。

そして関数Aに戻った後、関数Aも終了し、同様にスタック領域の「106」へ戻り、「106」を削除します。

と、このような流れになるのですが、話は戻ってCall Traceは、このように関数の呼び出し(Call)のスタックを追跡(Trace)した状態を吐き出したものになります。

Call Traceの見方

例えば以下のCall Traceの場合を考えます。

[    4.679750] Call Trace:
[    4.679774]  [<ffffffff812676b4>] dump_stack+0x44/0x55
[    4.679803]  [<ffffffff81055434>] warn_slowpath_common+0x9a/0xb3
[    4.679842]  [<ffffffffa005214f>] ? drm_wait_one_vblank+0x12c/0x145 [drm]
[    4.679870]  [<ffffffff81055494>] warn_slowpath_fmt+0x47/0x49
[    4.679896]  [<ffffffff81083c09>] ? finish_wait+0x57/0x60
[    4.679935]  [<ffffffffa005214f>] drm_wait_one_vblank+0x12c/0x145 [drm]
[    4.679959]  [<ffffffff81083d14>] ? wait_woken+0x70/0x70
[    4.680041]  [<ffffffffa01e44ef>] intel_atomic_commit+0x403/0x526 [i915]
[    4.680083]  [<ffffffffa00659fa>] drm_atomic_commit+0x48/0x4d [drm]
[    4.680124]  [<ffffffffa00e411f>] restore_fbdev_mode+0xee/0x26c 
[drm_kms_helper]
[    4.680178]  [<ffffffffa00e5b35>] 
drm_fb_helper_restore_fbdev_mode_unlocked+0x2b/0x6a [drm_kms_helper]
[    4.680218]  [<ffffffffa00e5bae>] drm_fb_helper_set_par+0x3a/0x46 
[drm_kms_helper]
[    4.680295]  [<ffffffffa01fa9a2>] intel_fbdev_set_par+0x12/0x4f [i915]
[    4.680320]  [<ffffffff812a9283>] fbcon_init+0x309/0x406
[    4.680345]  [<ffffffff81314fd5>] visual_init+0xc8/0x11d
[    4.680372]  [<ffffffff813166fc>] do_bind_con_driver+0x1ab/0x2cd
[    4.680400]  [<ffffffff81316ae6>] do_take_over_console+0x142/0x172
[    4.680427]  [<ffffffff812a8942>] do_fbcon_takeover+0x56/0x9a
[    4.680457]  [<ffffffff812abe1e>] fbcon_event_notify+0x31c/0x644
[    4.680484]  [<ffffffff8106cb08>] notifier_call_chain+0x37/0x59
[    4.680517]  [<ffffffff8106cd5f>] 
__blocking_notifier_call_chain+0x41/0x5a
[    4.680549]  [<ffffffff8106cd87>] blocking_notifier_call_chain+0xf/0x11
[    4.680577]  [<ffffffff812b0b0a>] fb_notifier_call_chain+0x16/0x18
[    4.680606]  [<ffffffff812b282a>] register_framebuffer+0x26f/0x2a7
[    4.680652]  [<ffffffffa00e5e66>] 
drm_fb_helper_initial_config+0x2ac/0x321 [drm_kms_helper]
[    4.680730]  [<ffffffffa01fb338>] 
intel_fbdev_initial_config+0x16/0x18 [i915]
[    4.680758]  [<ffffffff8106ddce>] async_run_entry_fn+0x34/0xbe
[    4.680786]  [<ffffffff81067583>] process_one_work+0x1b2/0x327
[    4.680812]  [<ffffffff81067e85>] worker_thread+0x277/0x36f
[    4.680843]  [<ffffffff81067c0e>] ? cancel_delayed_work_sync+0x10/0x10
[    4.680865]  [<ffffffff8106bf63>] kthread+0xcd/0xd5
[    4.680895]  [<ffffffff8106be96>] ? kthread_create_on_node+0x15c/0x15c
[    4.680921]  [<ffffffff814f801f>] ret_from_fork+0x3f/0x70
[    4.680952]  [<ffffffff8106be96>] ? kthread_create_on_node+0x15c/0x15c
[    4.680973] ---[ end trace f295b50a7b94aa26 ]---

最後の"kthread_create_on_node"というのが大元の関数で、それからret_from_fork、kthread_create_on_node、kthread、、、と呼び出していっています。

横にあるffffffff8106be96等の値がスタック領域に格納されているメモリアドレスです。

上から2番目にある"warn_slowpath_common"が耐え切れなくなり、最後に"dump_stack"によりCall Traceを吐き出した、となっています。

スポンサーリンク
スポンサーリンク
スポンサーリンク

シェアする

  • このエントリーをはてなブックマークに追加

フォローする

スポンサーリンク
スポンサーリンク