Linux Kernel(4.14) Hacks

rousalome.egloos.com

포토로그 Kernel Crash




IPI (Inter Processor Interrupts) 소개 및 디버깅 패치 (1) [Debugging] Tips

IPI (Inter Processor Interrupts)란 용어를 들어본 적이 있나요?
각 CPU간 통신을 하고 싶은 경우가 있거든요. 예를 들면, 다른 CPU를 깨우고 싶거나 다른 CPU가
특정 콜백 함수를 호출해서 원하는 동작을 시키고 싶은 경우죠. 

CPU 부하을 점검해서 일을 덜하고 있는 다른 CPU에 일을 시키는 네트워크 디바이스 드라이버나,
CPU Governor에서 다른 CPU Frequency를 높이고 싶을 경우에 주로 실행되는데요.

그런데 이 때 특정 콜백 함수가 너무 오래 실행되어 응답이 늦을 경우 시스템 오동작을 유발시킬 수가 있구요.
가끔 불량 ARM 코어에서는 특정 CPU가 응답을 늦게 주는 경우가 있어요.

이럴 때 써먹으면 좋은 디버깅 패치가 있어요. 아래 패치를 적용하면 CPU간 IPI 통신을 ftrace로 확인할 수 있어요.
diff --git a/arch/arm64/kernel/smp.c b/arch/arm64/kernel/smp.c
index d031a85..e31341a 100644
--- a/arch/arm64/kernel/smp.c
+++ b/arch/arm64/kernel/smp.c
@@ -841,7 +841,9 @@ void handle_IPI(int ipinr, struct pt_regs *regs)

        case IPI_CALL_FUNC:
                irq_enter();
+               trace_printk("++ IPI_CALL_FUNC ++\n");
                generic_smp_call_function_interrupt();
+               trace_printk("-- IPI_CALL_FUNC --\n");
                irq_exit();
                break;
                
diff --git a/kernel/smp.c b/kernel/smp.c
index b2ec21c..fc822cc 100644
--- a/kernel/smp.c
+++ b/kernel/smp.c
@@ -456,12 +456,13 @@ void smp_call_function_many(const struct cpumask *mask,
                        csd->flags |= CSD_FLAG_SYNCHRONOUS;
                csd->func = func;
                csd->info = info;
+               trace_printk("IPI is queued for target cpu : %d\n", cpu);
                llist_add(&csd->llist, &per_cpu(call_single_queue, cpu));
        }

        /* Send a message to all CPUs in the map */
        arch_send_call_function_ipi_mask(cfd->cpumask);
-
+       trace_printk("IPI triggered to %d cpus\n", cpumask_weight(cfd->cpumask));
        if (wait) {
                for_each_cpu(cpu, cfd->cpumask) {
                        struct call_single_data *csd;
 
ftrace log를 받아보면 아래와 같은데요. 해석을 좀 해볼께요.
[1][2]: CPU1과 CPU7에 IPI call을 Trigger해요.
[3][4]: CPU7과 CPU1이 IPI call을 잘 받고 있네요.
[5][6]: IPI call이 제대로 종료되었네요.
 <...>-822   [004] ...2    41.459370: smp_call_function_many: IPI target cpu : 1 //<<--[1]
           <...>-822   [004] ...2    41.459372: smp_call_function_many: IPI target cpu : 7 //<<--[2]
           <...>-822   [004] ...2    41.459374: smp_call_function_many: IPI sent to 2 cpus
        Binder_3-1592  [000] d..3    41.459375: sched_switch: prev_comm=Binder_3 prev_pid=1592 prev_prio=120 prev_state=D ==> next_comm=.lge.smartcover next_pid=2570 next_prio=120 extra_prev_state=m 
 logd.reader.per-834   [007] d.h.    41.459377: handle_IPI: + IPI_CALL_FUNC  //<<--[3]
 Ril Proxy Main -1250  [001] d.h.    41.459378: handle_IPI: + IPI_CALL_FUNC //<<--[4] 
 logd.reader.per-834   [007] d.h.    41.459380: handle_IPI: - IPI_CALL_FUNC  //<<--[5]
 Ril Proxy Main -1250  [001] d.h.    41.459382: handle_IPI: - IPI_CALL_FUNC //<<--[6] 
 
아래 ftrace log는 CPU3에서 CPU0/1에 IPI call을 Trigger하는군요. 
 <...>-617   [003] ...2    19.658070: smp_call_function_many: IPI target cpu : 0
           <...>-617   [003] ...2    19.658073: smp_call_function_many: IPI target cpu : 1
           <...>-617   [003] ...2    19.658075: smp_call_function_many: IPI sent to 2 cpus
           <...>-621   [001] d.h1    19.658079: handle_IPI: ++ IPI_CALL_FUNC ++
           <...>-620   [000] d.h1    19.658080: handle_IPI: ++ IPI_CALL_FUNC ++
         mmcqd/0-270   [002] d..3    19.658080: sched_switch: prev_comm=mmcqd/0 prev_pid=270 prev_prio=120 prev_state=R+ ==> next_comm=kworker/2:1H next_pid=293 next_prio=100 NORMAL/1024 ==> NORMAL/88761
           <...>-620   [000] d.h1    19.658084: handle_IPI: -- IPI_CALL_FUNC --
           <...>-621   [001] d.h1    19.658084: handle_IPI: -- IPI_CALL_FUNC --
 
이런 IPI call는 특정 변수에 큐잉(Queue)한 다음에  큐(Queue) 변수에서 요청된 큐를 처리하는 구조인데요.
그 정체는 call_single_queue이구요, per-cpu 타입이에요.

이제 Crash Tool로 변수를 직접 확인해 볼까요?

1> CPU5 IPI call
CPU5로 IPI call 큐잉(Queue) 정보를 보면 아래와 같아요. 음, CPU5에 drain_local_pages() 함수를 수행하라는 IPI call을 날렸나 보내요.
crash> p call_single_queue
PER-CPU DATA TYPE:
  struct llist_head call_single_queue;
PER-CPU ADDRESSES:
  [0]: edefc4c0
  [1]: edf074c0
  [2]: edf124c0
  [3]: edf1d4c0
  [4]: edf284c0
  [5]: edf334c0
  [6]: edf3e4c0
  [7]: edf494c0 
crash> struct list_head edf334c0 -px
struct list_head {
  struct list_head *next = 0xedf374a0
  -> {
       next = 0xedf37500,
       prev = 0xc01d63d4 <drain_local_pages>
     }  
crash> struct call_single_data 0xedf374a0
struct call_single_data {
  llist = {
    next = 0xedf37500
  },
  func = 0xc01d63d4 <drain_local_pages>,
  info = 0x0,
  flags = 0x1
}
 
2> CPU6 IPI call
이 경우는 CPU6이 smp_callback 함수를 호출하도록 IPI call을 수행하네요. 가장 많이 호출되는 callback 함수이랍니다.
crash> p call_single_queue
PER-CPU DATA TYPE:
  struct llist_head call_single_queue;
PER-CPU ADDRESSES:
  [0]: edefb4c0
  [1]edf064c0
  [2]: edf114c0
  [3]: edf1c4c0
  [4]: edf274c0
  [5]: edf324c0
  [6]: edf3d4c0
  [7]: edf484c0
crash> struct call_function_data -px 0xEC817EE8
struct call_function_data {
  struct call_single_data *csd = 0xedf364c0
  -> {
       llist = {
         next = 0x0
       },
       func = 0xc08487bc <smp_callback>, //<<--
       info = 0x0,
       flags = 0x1
     }
  cpumask = {{
      bits = {0xc042e910}
    }}
}
.

덧글

  • 밝은인생mike 2017/12/28 11:50 # 답글

    debugging patch를 적용하면, watchdog bite 가 발생했을 때, 어느 cpu에서 stuck되었는지를 알아볼 때 유용할거 같네요.^^
  • Guillermo 2017/12/28 12:39 #

    watchdog bite면 Qualcomm SoC를 말씀하시는 것 같은데요.

    아래 오픈 소스 사이트에 가서 소스를 열어 보면 watchdog kick을 수행하는 커널 쓰레드에서
    ping_other_cpus() 함수가 수행되어 현재 깨어 있는 CPU에 IPI콜을 전달하는군요.
    만약 제대로 응답이 없으면 Watchdog Kick을 못하겠죠? ^^.

    특히, 특정 디바이스에서 Watchdog Reset이 자주 발생할 때 IPI 디버그 패치를 적용하면 어떤 CPU가 응답이 없는지
    좀 더 명확하게 파악할 수 있는 것 같네요. 좋은 의견 감사합니다.
    https://android.googlesource.com/kernel/msm/+/android-8.1.0_r0.7/drivers/soc/qcom/watchdog_v2.c
    static void ping_other_cpus(struct msm_watchdog_data *wdog_dd)
    {
    int cpu;
    cpumask_clear(&wdog_dd->alive_mask);
    smp_mb();
    for_each_cpu(cpu, cpu_online_mask) {
    if (!cpu_idle_pc_state[cpu] && !cpu_isolated(cpu))
    smp_call_function_single(cpu, keep_alive_response, //<<--
    wdog_dd, 1);
    }
    }

    static __ref int watchdog_kthread(void *arg)
    {
    // .. 생략 ..
    while (!kthread_should_stop()) {
    while (wait_event_interruptible(
    wdog_dd->pet_complete,
    wdog_dd->timer_expired) != 0)
    ;
    if (wdog_dd->do_ipi_ping)
    ping_other_cpus(wdog_dd); //<<--
댓글 입력 영역