透過Tracepoint理解內(nèi)核 - 調(diào)度器框架和性能

靜態(tài)tracepoint預埋在內(nèi)核的關(guān)鍵位置, 通過這些預埋的tracepoint, 可以比較容易梳理出相關(guān)模塊的框架及主要流程. 相比于直接鉆到scheduler的實現(xiàn)細節(jié)中去, 我們先通過tracepoint及其相關(guān)工具去理解實現(xiàn)背后的邏輯, 細節(jié)總是不停變化, 而分析方法往往相對固定, 也更容易沉淀下來.

Tracepoint分類

通過perf命令可以列出系統(tǒng)所有的tracepoint:

$ sudo perf list | grep sched:
  sched:sched_kthread_stop                           [Tracepoint event]
  sched:sched_kthread_stop_ret                       [Tracepoint event]
  sched:sched_migrate_task                           [Tracepoint event]
  sched:sched_move_numa                              [Tracepoint event]
  sched:sched_pi_setprio                             [Tracepoint event]
  sched:sched_process_exec                           [Tracepoint event]
  sched:sched_process_exit                           [Tracepoint event]
  sched:sched_process_fork                           [Tracepoint event]
  sched:sched_process_free                           [Tracepoint event]
  sched:sched_process_hang                           [Tracepoint event]
  sched:sched_process_wait                           [Tracepoint event]
  sched:sched_stat_blocked                           [Tracepoint event]
  sched:sched_stat_iowait                            [Tracepoint event]
  sched:sched_stat_runtime                           [Tracepoint event]
  sched:sched_stat_sleep                             [Tracepoint event]
  sched:sched_stat_wait                              [Tracepoint event]
  sched:sched_stick_numa                             [Tracepoint event]
  sched:sched_swap_numa                              [Tracepoint event]
  sched:sched_switch                                 [Tracepoint event]
  sched:sched_wait_task                              [Tracepoint event]
  sched:sched_wake_idle_without_ipi                  [Tracepoint event]
  sched:sched_wakeup                                 [Tracepoint event]
  sched:sched_wakeup_new                             [Tracepoint event]
  sched:sched_waking                                 [Tracepoint event]

核心tracepoint

• sched_switch

• sched_wakeup

• sched_waking

• sched_migrate_task

Stat類型

該類型的tracepoint額外帶有delay的時間

• sched_stat_blocked

• sched_stat_iowait

• sched_stat_runtime

• sched_stat_sleep

• sched_stat_wait

其他

• sched_kthread_stop, sched_kthread_stop_ret. 在kthread_stop時產(chǎn)生, 一般不是scheduler性能調(diào)試的重點

• sched_move_numa, sched_swap_numa, sched_stick_numa. NUMA相關(guān), 從性能分析角度上看, 它們必須在我們的checklist中, 一定程度可以把它們當作是異常(USE)

• sched_pi_setprio. 用于實現(xiàn)rt_mutex的優(yōu)先級繼承, 比如用在futex上.

• sched_process_exec, sched_process_exit, sched_process_fork, sched_process_free. 進程相關(guān)的主要事件

• sched_process_hang. 進程hang

• sched_process_wait. 等子進程的狀態(tài)變化

• sched_wait_task. 等待其他任務unschedule, 比如用于ptrace.

• sched_wake_idle_without_ipi. 如果target cpu上的任務設置了TIF_POLLING_NRFLAG標記 (只有idle進程會設置), 這樣idle進程自己去poll TIF_NEED_RESCHED, 這樣就不用發(fā)ipi中斷去通知了

• sched_wakeup_new. 同sched_wakeup, 但針對的是新創(chuàng)建的任務

核心Tracepoint

sched_switch

當調(diào)度器決定schedule另一個task運行的時候, 也就是任務切換的時候, 會觸發(fā)該tracepoint. 核心邏輯如下:

__schedule
    next = pick_next_task(rq, prev, &rf);
    if (likely(prev != next))
        trace_sched_switch(preempt, prev, next);
        rq = context_switch(rq, prev, next, &rf);

我們稍微關(guān)注以下context_switch里面的切棧操作:

switch_to(prev, next, prev);
    prev = __switch_to_asm((prev), (next)));
        pushq %rbp, %rbx, %r12, %13, %14, %15  /* Save callee-saved registers */
        movq  %rsp, TASK_threadsp(%rdi)
        movq  TASK_threadsp(%rsi), %rsp  /* switch stack */
        popq  %15, %14, %13, %12, %rbx, %rbp  /* restore callee-saved registers */
        jmp   __switch_to

struct task_struct *__switch_to(struct task_struct *prev, struct task_struct *next);

注意這里的__switch_to_asm傳入了prev, 又返回了prev, 看似沒有必要, 但是因為context_switch函數(shù)涉及到2個task, 在切棧之前是A, 切棧之后就變成B了

• 對于切棧前的task A來說, prev指的就是A本身

• 對于切棧后的task B來說, prev指的還必須是A, switch到B之后還需要更新A的信息. 這里通過函數(shù)調(diào)用巧妙解決了2個task之間變量的傳遞.

ULK引入3個task來解釋switch_to, 我認為反而復雜了.

sched_wakeup / sched_waking

內(nèi)核會通過try_to_wake_up把任務喚醒, 這會涉及到這sched_wakeup和sched_waking兩個tracepoint.

try_to_wake_up
    if (p == current) ...
    trace_sched_waking(p);
    if (p->on_rq && ttwu_remote(p, wake_flags)) goto unlock;
        rq = __task_rq_lock(p, &rf);
        if (task_on_rq_queued(p))
            ret = 1;
            ttwu_do_wakeup(rq, p, wake_flags, &rf);
                check_preempt_curr(rq, p, wake_flags);
                p->state = TASK_RUNNING;
                trace_sched_wakeup(p);
    p->state = TASK_WAKING;
    cpu = select_task_rq(p, p->wake_cpu, SD_BALANCE_WAKE, wake_flags);
    if (task_cpu(p) != cpu)
        wake_flags |= WF_MIGRATED;
        set_task_cpu(p, cpu);
    ttwu_queue(p, cpu, wake_flags);
        return ttwu_queue_remote(p, cpu, wake_flags); if (sched_feat(TTWU_QUEUE) && !cpus_share_cache(smp_processor_id(), cpu))
            if (llist_add(&p->wake_entry, &cpu_rq(cpu)->wake_list))
                smp_send_reschedule(cpu); if (!set_nr_if_polling(rq->idle))
                    scheduler_ipi
                        sched_ttwu_pending();
                            ttwu_do_activate(rq, p, p->sched_remote_wakeup ? WF_MIGRATED : 0, &rf);
        rq = cpu_rq(cpu);
        rq_lock(rq, &rf);
        ttwu_do_activate(rq, p, wake_flags, &rf);
            activate_task(rq, p, en_flags);
                enqueue_task(rq, p, flags);
                    for_each_sched_entity(se)
                        break; if (se->on_rq)
                        enqueue_entity(cfs_rq, se, flags);
                            update_curr(cfs_rq);
                            update_stats_enqueue(cfs_rq, se, flags);
                            __enqueue_entity(cfs_rq, se); if (!curr)
                            se->on_rq = 1;
                p->on_rq = TASK_ON_RQ_QUEUED;
            ttwu_do_wakeup(rq, p, wake_flags, rf);
                check_preempt_curr(rq, p, wake_flags);
                p->state = TASK_RUNNING;
                trace_sched_wakeup(p);

上面需要關(guān)注的點:

• 可以喚醒current task

• 喚醒on_rq的task比較直接, 在sched_waking和sched_wakeup之間的時間非常短

• 當需要遷移到其他cpu時會有2種方案

• 通過ipi給target cpu發(fā)送中斷, 在中斷處理函數(shù)中完成wakeup的后面部分

• 直接在當前cpu上操作target cpu, 所以需要先執(zhí)行rq_lock操作, 可能會有鎖沖突

從上面可以看出, sched_waking和sched_wakeup在wakeup task過程中肯定都會發(fā)生, sched_waking事件在ttwu開始的時候觸發(fā), 而sched_wakeup在ttwu結(jié)束的時候觸發(fā). 一般情況下, 這2個tracepoint觸發(fā)的時間非?？拷? 但是不排除中間會有較大gap.

sched_migrate_task

從資源的角度看, 只有系統(tǒng)中存在多個同類資源(這里是cpu), 為了最大化資源利用率, 就會涉及到migration. 從性能角度看, 這個的影響是比較大的, 也是性能調(diào)試的時候必須關(guān)注的, migration有沒有及時, migration會不會太多 (locality).

Stat類型

為了使用stat類型的tracepoint, 我們需要先enable.

# sysctl kernel.sched_schedstats
kernel.sched_schedstats = 0
# sysctl -w kernel.sched_schedstats=1
kernel.sched_schedstats = 1

stat_iowait / stat_sleep / stat_blocked

update_stats_dequeue
    if (tsk->state & TASK_INTERRUPTIBLE)
        __schedstat_set(se->statistics.sleep_start, rq_clock(rq_of(cfs_rq)));
    if (tsk->state & TASK_UNINTERRUPTIBLE)
        __schedstat_set(se->statistics.block_start, rq_clock(rq_of(cfs_rq)));

update_stats_enqueue
    update_stats_enqueue_sleeper(cfs_rq, se); if (flags & ENQUEUE_WAKEUP)
        if (sleep_start)
            trace_sched_stat_sleep(tsk, delta);
        if (block_start)
            trace_sched_stat_iowait(tsk, delta); if (tsk->in_iowait)
            trace_sched_stat_blocked(tsk, delta);

• stat_sleep用于記錄TASK_INTERRUPTIBLE的時間

• stat_blocked用于記錄TASK_UNINTERRUPTIBLE的時間

• stat_iowait用于iowait的場景, 這種情況下stat_iowait和stat_blocked值是一樣的

stat_wait

stat_wait和上面的stat不一樣的地方在于, stat_wait更反映調(diào)度器本身的執(zhí)行情況.

update_stats_wait_start()
    wait_start = rq_clock(rq_of(cfs_rq));
    __schedstat_set(se->statistics.wait_start, wait_start);

update_stats_wait_end
    delta = rq_clock(rq_of(cfs_rq)) - schedstat_val(se->statistics.wait_start);
    trace_sched_stat_wait(p, delta); if (entity_is_task(se))

• wait的起始時間wait_start. 任務狀態(tài)切到runnable, 但是不能馬上在cpu上執(zhí)行

• task被搶占了, 那么wait_start就是搶占點. put_prev_entity并且prev->on_rq成立

• task喚醒的時候, 從enqueue_entity進入

• wait的結(jié)束時間

• 任務馬上要在cpu上執(zhí)行了, set_next_entity

• 任務enqueue后壓根沒能在該cpu上執(zhí)行就被dequeue了, update_stats_dequeue

stat_runtime

記錄任務的執(zhí)行時間, 包括runtime, vruntime

Scheduler框架

__schedule()的主要邏輯

if (!preempt && prev->state)
    if (signal_pending_state(prev->state, prev))
        prev->state = TASK_RUNNING;
    else
        deactivate_task(rq, prev, DEQUEUE_SLEEP | DEQUEUE_NOCLOCK);
            p->on_rq = (flags & DEQUEUE_SLEEP) ? 0 : TASK_ON_RQ_MIGRATING;
            dequeue_task(rq, p, flags);
                p->sched_class->dequeue_task(rq, p, flags);
                    dequeue_entity(cfs_rq, se, flags);
                        update_stats_dequeue(cfs_rq, se, flags);
                        __dequeue_entity(cfs_rq, se); if (se != cfs_rq->curr)  // 在move_queued_task中, moved task可能不是curr
                            rb_erase_cached(&se->run_node, &cfs_rq->tasks_timeline);
                        se->on_rq = 0;
next = pick_next_task(rq, prev, &rf);
    fair_sched_class.pick_next_task(rq, prev, rf);  // pick_next_task_fair
        put_prev_task(rq, prev); if (prev)
            put_prev_entity(cfs_rq, se);
                if (prev->on_rq)
                    update_curr(cfs_rq);
                    update_stats_wait_start(cfs_rq, prev);
                    __enqueue_entity(cfs_rq, prev);
                cfs_rq->curr = NULL;
        se = pick_next_entity(cfs_rq, NULL);
        set_next_entity(cfs_rq, se);
            if (se->on_rq)  // 什么時候不on_rq?
                update_stats_wait_end(cfs_rq, se);
                    trace_sched_stat_wait(p, delta);
                __dequeue_entity(cfs_rq, se);  // 'current' is not kept within the tree.
            update_stats_curr_start(cfs_rq, se);
                se->exec_start = rq_clock_task(rq_of(cfs_rq));
            cfs_rq->curr = se;
if (likely(prev != next))
    trace_sched_switch(preempt, prev, next);
    rq = context_switch(rq, prev, next, &rf);

性能調(diào)試

即使不是調(diào)度器的開發(fā)者, 有的時候也需要能夠?qū)φ{(diào)度器進行調(diào)試, 比如應用開發(fā)者或者系統(tǒng)管理員, 升級內(nèi)核后性能退化, 修改線程模型后性能不滿足預期等, 最終可能只需要動某個調(diào)度器的參數(shù)而已, 但是前提是能夠定位到這個參數(shù).

sched map

只要抓取sched:sched_switch一個tracepoint, 就可以抓到系統(tǒng)所有的切換事件, 以下perf sched map的輸出:

• 前面每列代表一個cpu, 后面2列是事件發(fā)生的時間戳和任務縮寫的映射

• 點(.)表示cpu在idle

• 星號(*)表示有事件發(fā)生

   .   .   .  *J0  .   .    40302.714499 secs J0 => containerd:1125
   .   .   .   J0  .  *K0   40302.714507 secs K0 => containerd:1094
   .   .   .   J0  .  *.    40302.714515 secs
   .   .   .  *.   .   .    40302.714517 secs
   .   .   .   .  *L0  .    40302.714522 secs L0 => containerd:1121
   .   .   .   .  *.   .    40302.714527 secs
   .   .   .   .   .  *K0   40302.714583 secs
   .   .   .   .   .  *.    40302.714586 secs
   .   .  *M0  .   .   .    40302.738012 secs M0 => cron:911
   .   .  *.   .   .   .    40302.738043 secs
   .   .   .   .   .  *N0   40302.802649 secs N0 => kworker/5706
   .   .   .   .   .  *.    40302.802657 secs
   .   .   .   .  *O0  .    40302.818889 secs O0 => chrome:1370

sched timehist

該命令可以獲得task的wait time, 特別地, 還能拿到sch delay. timehist統(tǒng)計的sch delay是通過sched_switch和sched_wakeup計算出來的, 而不是上面的stat_wait.

/*
 * Explanation of delta-time stats:
 *
 *            t = time of current schedule out event
 *        tprev = time of previous sched out event
 *                also time of schedule-in event for current task
 *    last_time = time of last sched change event for current task
 *                (i.e, time process was last scheduled out)
 * ready_to_run = time of wakeup for current task
 *
 * -----|------------|------------|------------|------
 *    last         ready        tprev          t
 *    time         to run
 *
 *      |-------- dt_wait --------|
 *                   |- dt_delay -|-- dt_run --|
 *
 *   dt_run = run time of current task
 *  dt_wait = time between last schedule out event for task and tprev
 *            represents time spent off the cpu
 * dt_delay = time between wakeup and schedule-in of task
 */

time    cpu  task name                       wait time  sch delay   run time
                        [tid/pid]                          (msec)     (msec)     (msec)
--------------- ------  ------------------------------  ---------  ---------  ---------
   43721.001384 [0001]                                0.000      0.000      0.000
   43721.001401 [0001]  avahi-daemon[950]                   0.000      0.000      0.017
   43721.001451 [0000]                                0.000      0.000      0.000
   43721.001468 [0000]  Chrome_IOThread[2401/2383]          0.000      0.000      0.016
   43721.001516 [0004]                                0.000      0.000      0.000

sched latency

這里的delay同timehist的sch delay.

# perf sched latency -s max

 -----------------------------------------------------------------------------------------------------------------
  Task                  |   Runtime ms  | Switches | Average delay ms | Maximum delay ms | Maximum delay at       |
 -----------------------------------------------------------------------------------------------------------------
  rcu_preempt:11        |      0.323 ms |       13 | avg:    0.020 ms | max:    0.141 ms | max at:  43721.824102 s
  kworker/110084 |      0.636 ms |        7 | avg:    0.047 ms | max:    0.141 ms | max at:  43721.716104 s
  ThreadPoolForeg:(3)   |      1.148 ms |       20 | avg:    0.012 ms | max:    0.139 ms | max at:  43721.797089 s
  containerd:(7)        |      1.863 ms |       46 | avg:    0.012 ms | max:    0.070 ms | max at:  43721.068446 s
  gnome-shell:1612      |      2.517 ms |       16 | avg:    0.011 ms | max:    0.054 ms | max at:  43721.982652 s

perf inject

通過關(guān)聯(lián)以下2個tracepoint, 我們可以得到任務sleep的時長及其對應的callchain

• sched_iowait/sleep/blocked. 獲得sleep的時長

• sched_switch. 獲得調(diào)用棧

commit 26a031e136f4f8dc82c64df48cca0eb3b5d3eb4f
Author: Andrew Vagin 
Date:   Tue Aug 7 1604 2012 +0400

    perf inject: Merge sched_stat_* and sched_switch events

    You may want to know where and how long a task is sleeping. A callchain
    may be found in sched_switch and a time slice in stat_iowait, so I add
    handler in perf inject for merging this events.

    My code saves sched_switch event for each process and when it meets
    stat_iowait, it reports the sched_switch event, because this event
    contains a correct callchain. By another words it replaces all
    stat_iowait events on proper sched_switch events.

其他

這里列出一些調(diào)試的想法, 暫時沒有整理和一一展開

• 性能調(diào)試要考慮工具的開銷, 比如perf的開銷是否會影響到應用的性能. 我們可以使用eBPF重寫上面的perf的功能, eBPF因為能夠在內(nèi)核中直接聚合, 開銷相比perf會小

• 雖然tracepoint能提供更多更完整的調(diào)試信息, 但是其他的統(tǒng)計工具比如schedstat等對調(diào)試也會有幫助, 很多時候只能用這些一直在搜集的信息, 而不是所有場景都能復現(xiàn)然后上去通過tracepoint搜集信息的

• 以上涉及的工具都還是文本界面的, 圖形界面的工具會更有優(yōu)勢. 文本的好處是可以再加工, 圖像的好處是更直觀, 更容易發(fā)現(xiàn)問題

• 和scheduler相關(guān)的性能問題主要是兩個方面, 一是怎么定位應用程序的off-cpu, 二是scheduler自身的影響, 都有一些相對固定的方法

• 有了這些tracepoint以及動態(tài)添加的kprobe, 我們很容易拿到應用程序schedule相關(guān)的信息, 比如在context switch in/out時收集信息, 就可以生成帶callchain的off-cpu flamegraph

• 如果某個cpu忙應該看到什么現(xiàn)象, 我們可以去獲取cpu runqueue的長度

• 如果task的某個函數(shù)執(zhí)行時間過長, 我們可以檢查它是在cpu上執(zhí)行慢, 還是在等資源. 如果是調(diào)度不及時, 我們可以看到當時它runnable的時長, 以及其他cpu的狀態(tài)

• 如果我們已經(jīng)有了cpu視角和task視角, 我們看到大量cpu idle而只有某個task在跑, 那么一種合理的推測是該task是否阻塞其他task了

• 調(diào)試其實就是把很多現(xiàn)象關(guān)聯(lián)起來, 也就是說孤立地去看一種現(xiàn)象往往收獲不大. 一般來說我們可以通過時間軸把這些事件關(guān)聯(lián)起來, 從資源的角度(比如每個cpu的在任意時間的使用情況), 從消費者的角度(比如每個進程的運行狀態(tài)/路徑)

• 如果某個cpu忙其他cpu閑會有什么現(xiàn)象, 以每個cpu為視角, 通過時間軸把所有的cpu關(guān)聯(lián)起來, 使用不同的顏色表示runqueue的長度, 這樣生成的圖可以很容易看出migration是否及時, 這樣的資源利用圖是非常有必要的, 有點類似htop, 但是更加精細