IPI (Inter Processor Interrupts) 소개 및 디버깅 패치 (1)

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}

    }}

}

.