Arm Linux Kernel Hacks

rousalome.egloos.com

포토로그 Kernel Crash


통계 위젯 (화이트)

6363
1898
209235


[라즈베리파이]인터럽트 컨택스트란(1) 5. 인터럽트

인터럽트 컨택스트란

인터럽트가 발생하면 즉시 인터럽트 벡터 주소로 프로그램 카운터가 바뀝니다. 이후 인터럽트 서브 루틴이 실행합니다. 현재 수행 중인 코드가 인터럽트가 발생한 다음 호출되는 서브 루틴 중 하나라고 볼 수 있습니다. ftrace와 커널 로그로 조금 더 구체적으로 인터럽트 컨택스트에 대해서 알아보겠습니다. 


ftrace와 커널 로그로 인터럽트 컨택스트 확인하기
아래는 touch_irq_handler 함수에 필터를 걸고 받은 ftrace 로그입니다..
=> touch_irq_handler
=> handle_irq_event_percpu
=> handle_irq_event
=> handle_edge_irq
=> generic_handle_irq
=> msm_gpio_irq_handler
=> generic_handle_irq
=> __handle_domain_irq
=> gic_handle_irq
=> __irq_svc
=> __slab_alloc
=> kmem_cache_alloc
=> jbd2__journal_start
=> __ext4_journal_start_sb
=> ext4_da_write_begin
=> generic_perform_write
=> __generic_file_write_iter
=> ext4_file_write_iter
=> new_sync_write
=> vfs_write
=> SyS_write
=> ret_fast_syscall

참고로 touch_irq_handler 함수로 ftrace 스택 트레이서를 설정하기 위해서 아래와 같이 설정하면 됩니다.
"echo 0 > d/tracing/tracing_on"

"echo 5000 > /d/tracing/buffer_size_kb"
"echo function > d/tracing/current_tracer"
"sleep 1"

"echo touch_irq_handler  > d/tracing/set_ftrace_filter"
"sleep 1"

"echo 1 > d/tracing/options/func_stack_trace"
"sleep 1"

"echo 1 > d/tracing

위 로그를 분석하면 ret_fast_syscall 함수부터 __slab_alloc 함수 구간까지 프로세스 컨택스트이고, __irq_svc 함수부터 touch_irq_handler 함수 구간까지가 인터럽트 컨택스트입니다. 즉, 인터럽트가 발생하고 난 다음 서브 루틴 동작 구간을 인터럽트 컨택스트라고 말할 수 있습니다.

함수 흐름을 보면 터치 인터럽트가 발생해서 메모리 할당 동작을 멈추고 인터럽트 서브 루틴이 실행됐네요. 이렇게 메모리를 할당하는 중요한 동작에서 인터럽트 발생으로 실행을 멈추는군요. (참고로 인터럽트 서비스 루틴에서는 메모리 할당할 때 GFP_ATOMIC 옵션을 줘야 합니다.)

프로세스가 스택 공간에서 어떻게 동작하는지 조금 더 자세히 설명해 드리면, 우선 프로세스가 생성될 때는 커널은 프로세스에게 스택 공간(스택 사이즈: 0x2000) 을 할당합니다. 구내식당에서 식판 주듯이요. 프로세스 입장에서 스택은 운동장으로 볼 수 있습니다. 프로세스는 스택 메모리 공간 내에서 실행되기 때문이죠. 함수를 호출하거나 로컬 변수 사용할 때 자신에게 부여된 고유 스택 메모리를 사용합니다. 그럼 프로세스별로 할당된 스택 주소는 어떻게 확인할 수 있나요? 태스크 디스크립터 멤버 struct task_struct.stack로 확인할 수 있습니다. 그런데 이 주소는 스택 Top 주소입니다. 그럼 프로세스에서 함수들을 실행할 때는 스택 Bottom 주소인 struct task_struct.stack + 0x2000 에서 스택 Top 주소인struct task_struct.stack 방향으로 즉 높은 주소에서 낮은 주소로 스택을 사용합니다.

이렇게 프로세스가 스택 메모리 공간에서 실행 중 인터럽트가 발생하면 인터럽트 벡터와 인터럽트 서비스 루틴도 프로세스 스택 공간에서 실행됩니다. 전세 살 듯이 잠시 프로세스 스택 공간을 활용하는 거죠.
 
리눅스 커널에서 인터럽트 처리가 중요한데 ARM64 비트 아키텍처에서는 프로세스가 돌고 있는 스택을 빌려 계속 쓰다 보니 인터럽트 서브 루틴이 너무 길어져 스택 공간이 부족할 때도 있습니다. 그래서 ARM64 아키텍처에서는 인터럽트 전용 스택인 IRQ Stack을 할당해서 인터럽트 벡터부터 이 스택 공간에서 처리되도록 합니다. 참고로ARM32 아키텍처인 라즈베리파이는 프로세스가 쓰는 스택 공간을 사용합니다.

이번에는 커널 로그로 인터럽트 컨택스트 구간을 확인하겠습니다. 아래 커널 로그는 __irq_svc(asm)--unwind_backtrace() 함수들은 인터텁트 컨택스트에서 수행되며, start_kernel() --arch_cpu_idle() 함수 구간은 프로세스 컨택스트라고 볼 수 있습니다. 참고로 아래 콜스택은 WARN() 매크로가 수행되면 커널 로그로 출력되는데, show_stack(NULL, NULL)이란 함수를 호출해도 똑 같은 디버깅 정보를 출력합니다.

[출처: https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable.git/commit/?id=bbe097f092b0d13e9736bd2794d0ab24547d0e5d]

.

WARNING: CPU: 0 PID: 0 at include/linux/usb/gadget.h:405
 ecm_do_notify+0x188/0x1a0
 Modules linked in:
 CPU: 0 PID: 0 Comm: swapper Not tainted 4.7.0+ #15
 Hardware name: Atmel SAMA5
 [<c010ccfc>] (unwind_backtrace) from [<c010a7ec>] (show_stack+0x10/0x14)
 [<c010a7ec>] (show_stack) from [<c0115c10>] (__warn+0xe4/0xfc)
 [<c0115c10>] (__warn) from [<c0115cd8>] (warn_slowpath_null+0x20/0x28)
 [<c0115cd8>] (warn_slowpath_null) from [<c04377ac>] (ecm_do_notify+0x188/0x1a0)
 [<c04377ac>] (ecm_do_notify) from [<c04379a4>] (ecm_set_alt+0x74/0x1ac)
 [<c04379a4>] (ecm_set_alt) from [<c042f74c>] (composite_setup+0xfc0/0x19f8)
 [<c042f74c>] (composite_setup) from [<c04356e8>] (usba_udc_irq+0x8f4/0xd9c)
 [<c04356e8>] (usba_udc_irq) from [<c013ec9c>] (handle_irq_event_percpu+0x9c/0x158)
 [<c013ec9c>] (handle_irq_event_percpu) from [<c013ed80>] (handle_irq_event+0x28/0x3c)
 [<c013ed80>] (handle_irq_event) from [<c01416d4>] (handle_fasteoi_irq+0xa0/0x168)
 [<c01416d4>] (handle_fasteoi_irq) from [<c013e3f8>] (generic_handle_irq+0x24/0x34)
 [<c013e3f8>] (generic_handle_irq) from [<c013e640>] (__handle_domain_irq+0x54/0xa8)
 [<c013e640>] (__handle_domain_irq) from [<c010b214>] (__irq_svc+0x54/0x70)
 [<c010b214>] (__irq_svc) from [<c0107eb0>] (arch_cpu_idle+0x38/0x3c)
 [<c0107eb0>] (arch_cpu_idle) from [<c0137300>] (cpu_startup_entry+0x9c/0xdc)
 [<c0137300>] (cpu_startup_entry) from [<c0900c40>] (start_kernel+0x354/0x360)
 [<c0900c40>] (start_kernel) from [<20008078>] (0x20008078)
 ---[ end trace e7cf9dcebf4815a6 ]---J6


in_interrupt 함수란

리눅스 커널은 수많은 함수들이 각자 서로를 호출하며 실행됩니다. 특정 함수는 커널 쓰레드 레벨에서만 실행되는데 대부분 함수는 인터럽트 컨택스트에서도 호출될 수 있습니다. 인터럽트 서비스 루틴은 실행 중인 프로세스를 멈추고 동작하므로 인터럽트 컨택스트 조건에서만 신속하게 코드를 실행시키고 싶을 때가 있습니다. 그럼 현재 실행 중인 코드가 인터럽트 컨택스트 구간인지 어떻게 알 수 있을까요? in_interrupt()란 매크로가 이 정보를 알려줍니다. 


아래 패치는__rh_alloc() 함수가 인터럽트 컨택스트로 호출이 될 때, GFP_ATOMIC옵션으로 빨리 메모리 할당을 시도합니다. 대신 프로세스 컨택스트인 경우 GFP_KERNEL 옵션으로 메모리를 할당합니다. 참고로 GFP_ATOMIC 옵션으로 메모리를 할당하면 프로세스는 휴면하지 않고 메모리를 할당하고, GFP_KERNEL 옵션인 경우 메모리 할당 실패 시 휴면할 수 있습니다.

diff --git a/drivers/md/dm-region-hash.c b/drivers/md/dm-region-hash.c
index b929fd5..1325a8a 100644
--- a/drivers/md/dm-region-hash.c
+++ b/drivers/md/dm-region-hash.c
@@ -289,7 +289,12 @@ static struct dm_region *__rh_alloc(struct dm_region_hash *rh, region_t region)
  {
         struct dm_region *reg, *nreg;
 
 -       nreg = mempool_alloc(rh->region_pool, GFP_ATOMIC);
 +       gfp_t gfp_flag = GFP_KERNEL;
 +       if (in_interrupt()) {
 +               gfp_flag = GFP_ATOMIC;
 +       }
 +       nreg = mempool_alloc(flush_entry_pool, gfp_flag);
 +
         if (unlikely(!nreg))
                 nreg = kmalloc(sizeof(*nreg), GFP_NOIO | __GFP_NOFAIL);

이제 in_interrupt 코드를 살펴보겠습니다. 아래 코드를 보면 실제 irq_count() 매크로로 매핑되어 preempt_count() 매크로로 처리하는 값과 HARDIRQ_MASK | SOFTIRQ_MASK 비트 마스크와 OR 비트 연산을 수행합니다.

#define in_interrupt()  (irq_count())
    
 #define irq_count() (preempt_count() & (HARDIRQ_MASK | SOFTIRQ_MASK \
      | NMI_MASK))  
 
 SOFTIRQ_MASK: 0xff00,  SOFTIRQ_OFFSET: 0x100 
 HARDIRQ_MASK: 0xf0000, HARDIRQ_OFFSET: 0x10000

그럼 preempt_count 코드를 좀 더 살펴보면, 현재 구동 중인 함수 내에서 확인되는 스택 주소를 통해 스택 상단 Top 주소를 얻어 온 후 (struct thread_info *) 구조체의 preempt_count 멤버에서 얻어오는 값입니다. 


커널 프로세스마다 스택 Top 주소에 이 구조체 데이터를 저장합니다. 정리하면 in_interrupt()란 매크로는 현재 프로세스의 스택에 저장된 (struct thread_info *) 구조체의 preempt_count 멤버를 읽습니다. 해당 코드를 계속 살펴보겠습니다.

[1]: 스택 주소를 sp 지역 변수로 읽어 옵니다.
[2]: 스택 가장 낮은 주소(Top주소)를 계산합니다.
[3]: struct thread_info.preempt_count 멤버를 리턴 합니다.
static __always_inline int preempt_count(void)
{
  return current_thread_info()->preempt_count;  [3]
}
 
[kernel/arch/arm/include/asm/thread_info.h]
static inline struct thread_info *current_thread_info(void)
{
  register unsigned long sp asm ("sp"); //  [1]
  return (struct thread_info *)(sp & ~(THREAD_SIZE - 1));  [2]
}

아래는 코어 덤프를 로딩해서 Trace32 프로그램으로 확인한struct thread_info 자료 구조입니다. preempt_count값은 0x00010002로 현재 프로세스가 인터럽트 컨택스트에서 실행 중임을 알 수 있습니다. 

(struct thread_info*)(0xE359B908 & ~0x1fff) = 0xE359A000 -> (
     flags = 0x2,
     preempt_count = 0x00010002, // <-- HARDIRQ_OFFSET
     addr_limit = 0xBF000000,
     task = 0xD0B5EA40,  //<< <-- 태스크 디스크립터
     exec_domain = 0xC1A1AF1C,
     cpu = 0x0,
     cpu_domain = 0x15,

그럼, struct thread_info.preempt_count 멤버 0x00010002 HARDIRQ_OFFSET 비트를 어느 함수에서 설정할까요? 코드를 조금 더 살펴보면 __irq_enter 매크로에서 HARDIRQ_OFFSET 비트를 설정하고 있습니다.

__handle_domain_irq 함수에서 인터럽트 핸들러를 호출하기 전 irq_enter란 함수를 호출합니다. 함수 이름대로 IRQ(Interrupt Request)를 처리 시작을 나타내는 표시로 보입니다. 제 생각에 irq_enter보다 irq_context_enter로 함수 이름을 바꾸면 조금 더 함수를 쉽게 이해할 것 같습니다.
int __handle_domain_irq(struct irq_domain *domain, unsigned int hwirq,
    bool lookup, struct pt_regs *regs)
 {
  struct pt_regs *old_regs = set_irq_regs(regs);
  unsigned int irq = hwirq;
  int ret = 0;
 
  irq_enter();  // <--
 
 //skip
  if (unlikely(!irq || irq >= nr_irqs)) {
   ack_bad_irq(irq);
   ret = -EINVAL;
  } else {
   generic_handle_irq(irq); // <-- ISR 호출
  }
 
  irq_exit();  // <--
  set_irq_regs(old_regs);
  return ret;
 }

irq_enter 함수는 결국 __irq_enter 함수를 호출하는데 __irq_enter 매크로 함수를 자세히 살펴보면 current_thread_info()->preempt_count란 멤버에 HARDIRQ_OFFSET 비트를 더합니다. 

#define __irq_enter()     \
  do {      \
   account_irq_enter_time(current); \
   preempt_count_add(HARDIRQ_OFFSET); \ //<<--
   trace_hardirq_enter();   \
  } while (0) 



이후 인터럽트 핸들러가 수행되고 난 후 struct thread_info.preempt_count 멤버에서 HARDIRQ_OFFSET 비트는 아래 코드 흐름에서 해제됩니다.


아래 코드를 보면 current_thread_info()->preempt_count멤버에서 HARDIRQ_OFFSET 비트를 뺍니다.

#define __irq_exit()     \
  do {      \
   trace_hardirq_exit();   \
   account_irq_exit_time(current);  \
   preempt_count_sub(HARDIRQ_OFFSET); \
  } while (0) 
 
정리하면 in_interrupt 함수는 현재 구동 중인 프로세스 스택 Top 주소에 위치한 current_thread_info()->preempt_count멤버이며 인터럽트 서비스 루틴이 실행되기 전 __irq_enter 함수에서 HARDIRQ_OFFSET를 더하고 인터럽트 서비스 루틴이 종료되면 해제합니다.

그럼 이제 패치를 작성해서 위에서 설명한 값이 커널 로그로 어떤 값인지 실제 시스템에서 확인하겠습니다.

인터럽트 핸들러에 아래 코드를 반영하고 로그를 받아보면 in_interrupt() 함수 리턴값을 볼 수 있습니다.

[1]: current란 매크로는 현재 실행 중인 프로세스의 태스크 디스크립터 주소에 접근할 수 있습니다. current->stack는 현재 실행 중인 프로세스의 스택 Top주소인데 이 주소로 preempt_count 멤버 변수에 접근할 수 있습니다.
[2]: 스택 탑(Top) 주소에서 struct thread_info 란 구조체로 캐스팅합니다.
[3]: in_interrupt와 struct thread_info.preempt_count 값을 출력합니다.
diff --git a/drivers/input/touchscreen/touch_core.c b/drivers/input/touchscreen/touch_core.c
index 9cbf6ad..f148cd5 100644
--- a/drivers/input/touchscreen/touch_core.c
+++ b/drivers/input/touchscreen/touch_core.c
@@ -170,10 +170,20 @@ static void touch_core_initialize(struct touch_core_data *ts)

 irqreturn_t touch_irq_handler(int irq, void *dev_id)
 {
+       void *stack;
+       struct thread_info *current_thread;
+
        struct touch_core_data *ts = (struct touch_core_data *) dev_id;
+
+       stack = current->stack;  // [1]
+       current_thread = (struct thread_info *)stack;
+
+       printk("[+] in_interrupt: 0x%08x, preempt_count = 0x%08x \n", (unsigned int)in_interrupt(), (unsigned int)current_thread->preempt_count);

        TOUCH_TRACE();
 
커널 로그를 받아보면, in_interrupt() 함수는 현재 실행 중인 프로세스 스택에 저장된 struct thread_info->preempt_count 값에서 HARDIRQ_OFFSET 비트만 출력하기 위해 HARDIRQ_MASK로 마스킹한 결과를 리턴 합니다.
<6>[  129.931951 / 01-27 17:32:40.057][1] CPU1: Booted secondary processor
<6>[  129.935636 / 01-27 17:32:40.057][0] CPU0: Booted secondary processor
<6>[130.452743][2] [+] in_interrupt: 0x00010000, preempt_count = 0x00010001 
<6>[130.458822][7] [Touch] 1 finger pressed:<1>(xxxx,xxxx,xxxx)
<6>[130.469673][2] [+] in_interrupt: 0x00010000, preempt_count = 0x00010001 
<6>[130.486154][2] [+] in_interrupt: 0x00010000, preempt_count = 0x00010001 
<6>[130.502913][2] [+] in_interrupt: 0x00010000, preempt_count = 0x00010001

인터럽트 컨택스트에서 스케쥴링을 하면?
만약 인터럽트 컨택스트에서 프로세스가 휴면하면 어떤 일이 벌어질까요? 정답은 커널은 이를 감지하고 커널 패닉을 유발시킵니다.

인터럽트 컨택스트에서 스케쥴링을 하면 안 됩니다. 왜냐면, 짧은 시간에 인터럽트 핸들러를 실행하고 인터럽트 벡터로 다시 돌아가 이미 중단시킨 프로세스 동작시켜야 하기 때문이죠. 그런데 인터럽트 컨택스트에서 스케쥴링을 하면 커널 입장에서 많은 일을 해야 합니다. 당연히 시간이 오래 걸리죠.
 
그럼 인터럽트 컨택스트에서 스케쥴링 할 때 어떤 흐름으로 커널 패닉이 발생하는지 살펴보겠습니다. 프로세스가 스케쥴링 즉 휴면할 때 __schedule() 함수를 호출합니다. 이 함수를 열어보면 앞 단에 schedule_debug()란 함수를 호출해서 현재 프로세스가 휴면할 수 있는 조건인지 점검합니다. 

혹시 세니티 체크(Sanity Check)이란 용어를 들어보신 적이 있나요? 어떤 함수에 전달되는 파라미터가 예상했던 값인지 점검하는 에러 체크 루틴이죠. 커널 핵심 함수 구현 부 앞 단에 함수 파라미터들이 정상값인지 점검하는 코드가 많습니다. 위 코드 흐름에서는schedule_debug() 함수가 이 역할을 수행합니다.

인터럽트 컨택스트에서 아래 함수가 호출되면 in_atomic_preempt_off [1]조건에 걸려 커널 패닉으로 리셋됩니다.
static inline void schedule_debug(struct task_struct *prev)
{
#ifdef CONFIG_SCHED_STACK_END_CHECK
if (unlikely(task_stack_end_corrupted(prev)))
panic("corrupted stack end detected inside scheduler\n");
#endif
/*
* Test if we are atomic. Since do_exit() needs to call into
* schedule() atomically, we ignore that path. Otherwise whine
* if we are scheduling when we should not.
*/
if (unlikely(in_atomic_preempt_off() && prev->state != TASK_DEAD)) // <-- [1]
__schedule_bug(prev); //<< 
rcu_sleep_check();

profile_hit(SCHED_PROFILING, __builtin_return_address(0));

schedstat_inc(this_rq(), sched_count);
}

#define in_atomic_preempt_off() \
((preempt_count() & ~PREEMPT_ACTIVE) != PREEMPT_CHECK_OFFSET)

이렇게 인터럽트 컨택스트에서 스케쥴링을 하다가 발생하는 커널 패닉은 리눅스 커널 커뮤니티에서 자주 볼 수 있는 버그입니다. 

이와 관련된 기존 이슈 하나 소개하겠습니다.(https://patchwork.kernel.org/patch/4864261/) 아래 커널 로그는 인터럽트 컨택스트에서 뮤텍스락을 걸다가 커널 패닉이 발생했다고 말해줍니다. 참고로 뮤텍스락은 뮤텍스락을 다른 프로세스가 잡고 있으면 바로 휴면에 들어가기 때문에 인터럽트 컨택스트에서 쓰면 안 되는 함수입니다. 
BUG: sleeping function called from invalid context at ../kernel/locking/mutex.c:583
in_atomic(): 1, irqs_disabled(): 128, pid: 0, name: swapper/0
------------[ cut here ]------------
WARNING: CPU: 2 PID: 4828 at ../kernel/locking/mutex.c:479 mutex_lock_nested+0x3a0/0x3e8()
DEBUG_LOCKS_WARN_ON(in_interrupt())
Modules linked in:
CPU: 2 PID: 4828 Comm: Xorg.bin Tainted: G        W      3.17.0-rc3-00234-gd535c45-dirty #819
[<c0216690>] (unwind_backtrace) from [<c0212174>] (show_stack+0x10/0x14)
[<c0212174>] (show_stack) from [<c0867cc0>] (dump_stack+0x98/0xb8)
[<c0867cc0>] (dump_stack) from [<c02492a4>] (warn_slowpath_common+0x70/0x8c)
[<c02492a4>] (warn_slowpath_common) from [<c02492f0>] (warn_slowpath_fmt+0x30/0x40)
[<c02492f0>] (warn_slowpath_fmt) from [<c086a3f8>] (mutex_lock_nested+0x3a0/0x3e8)
[<c086a3f8>] (mutex_lock_nested) from [<c0294d08>] (irq_find_host+0x20/0x9c)
[<c0294d08>] (irq_find_host) from [<c0769d50>] (of_irq_get+0x28/0x48)
[<c0769d50>] (of_irq_get) from [<c057d104>] (platform_get_irq+0x1c/0x8c)
[<c057d104>] (platform_get_irq) from [<c021a06c>] (cpu_pmu_enable_percpu_irq+0x14/0x38)
[<c021a06c>] (cpu_pmu_enable_percpu_irq) from [<c02b1634>] (flush_smp_call_function_queue+0x88/0x178)
[<c02b1634>] (flush_smp_call_function_queue) from [<c0214dc0>] (handle_IPI+0x88/0x160)
[<c0214dc0>] (handle_IPI) from [<c0208930>] (gic_handle_irq+0x64/0x68)
[<c0208930>] (gic_handle_irq) from [<c0212d04>] (__irq_svc+0x44/0x5c)



.


덧글

댓글 입력 영역