Linux Kernel(4.14) Hacks

rousalome.egloos.com

포토로그 Kernel Crash

프로필

리눅스 커널 분석(4.x) 및 크래시 디버깅 내용을 세미나와 강의를 위해 정리한 블로그입니다. by Guillermo

카테고리

메뉴릿

최근 트랙백

RSS

RSS

[라즈베리파이][리눅스커널] IRQ Thread는 언제 생성할까?[2] #CS [라즈베리파이]인터럽트후반부


여기까지 request_threaded_irq 함수를 호출하면 결국 kthread_create 함수가 호출되어 IRQ Thread를 생성하는 코드를 짚어 봤습니다. 이제 분석한 대로 라즈베리파이에서 동작하는지 알아봐야겠죠. 이를 알아 보기 위한 코드를 소개할게요.
diff --git a/kernel/kthread.c b/kernel/kthread.c
index 1c19edf82..0bc8a0037 100644
--- a/kernel/kthread.c
+++ b/kernel/kthread.c
@@ -275,13 +275,25 @@ struct task_struct *__kthread_create_on_node(int (*threadfn)(void *data),
1   struct task_struct *task;
2  struct kthread_create_info *create = kmalloc(sizeof(*create),
3       GFP_KERNEL);
4 +
5 + int irq_thread_enable = !strncmp(namefmt, "irq", 3); 
6 if (!create)
7 return ERR_PTR(-ENOMEM);
8  create->threadfn = threadfn;
9  create->data = data;
10  create->node = node;
11  create->done = &done;
12+
13+    if (irq_thread_enable) {
14+        void *irq_threadfn = (void*)threadfn;
15+        
16+        printk("[+] irq_thread handler: %pS caller:(%pS) \n", 
17+ irq_threadfn, (void *)__builtin_return_address(0)); 
18+        dump_stack();
19+ }
20 
  spin_lock(&kthread_create_lock);
  list_add_tail(&create->list, &kthread_create_list);

이 패치 코드에 대한 이해를 돕기 위해 패치 적용 전__kthread_create_on_node 함수의 원래 코드를 보여드릴게요. 아래 화살표를 친 부분에 코드가 추가된 것이지요.
struct task_struct *__kthread_create_on_node(int (*threadfn)(void *data),
    void *data, int node,
    const char namefmt[],
    va_list args)
{
DECLARE_COMPLETION_ONSTACK(done);
struct task_struct *task;
struct kthread_create_info *create = kmalloc(sizeof(*create),
     GFP_KERNEL);
// <<-- 첫 번째 코드: irq_thread_enable = !strncmp(namefmt, "irq", 3);

if (!create)
return ERR_PTR(-ENOMEM);
create->threadfn = threadfn;
create->data = data;
create->node = node;
create->done = &done;

// <<-- 두 번째 코드: if (irq_thread_enable) {

이 점 참고하시고 패치 코드를 작성하시길 바랍니다.

그런데, 그 동안 한 번도 분석 안 한 __kthread_create_on_node 함수에 IRQ Thread를 생성하는 콜스택을 커널 로그로 저장하는 코드를 작성한 이유가 궁금하지는 않나요?
static int
setup_irq_thread(struct irqaction *new, unsigned int irq, bool secondary)
{
//...
if (!secondary) {
t = kthread_create(irq_thread, new, "irq/%d-%s", irq,
   new->name);

우리는 set_up_irqthread 함수에서 kthread_create 함수를 호출하는 코드를 봤습니다. 그런데 kthread_create 함수를 호출하면 __kthread_create_on_node 함수가 호출됩니다. 그래서 이 코드를 작성한 것이죠. 다음 코드에서 볼드체로 된 부분을 눈여겨보세요.
#define kthread_create(threadfn, data, namefmt, arg...) \
kthread_create_on_node(threadfn, data, NUMA_NO_NODE, namefmt, ##arg)

struct task_struct *kthread_create_on_node(int (*threadfn)(void *data),
   void *data, int node,
   const char namefmt[],
   ...)
{
struct task_struct *task;
va_list args;

va_start(args, namefmt);
task = __kthread_create_on_node(threadfn, data, node, namefmt, args);

우리는 kthread_create 함수를 호출하면 커널 쓰레드를 생성한다고 알고 있습니다. 그런데 kthread_create는 구현부를 보면 kthread_create는 kthread_create_on_node로 치환되는 매크로 함수라는 사실을 알 수 있습니다. 그런데 kthread_create_on_node 함수를 열어보면 __kthread_create_on_node 함수를 호출합니다.

이제 패치 코드를 분석할 차례입니다. 우선 먼저 수정한 4번째 줄 코드부터 보겠습니다.
struct task_struct *__kthread_create_on_node(int (*threadfn)(void *data),
    void *data, int node,
    const char namefmt[],
    va_list args)
4 +
5 + int irq_thread_enable = !strncmp(namefmt, "irq", 3); 
6 +      char *process_name = &namefmt[0];

__kthread_create_on_node 함수로 전달되는 namefmt란 파라미터를 “irq” 문자열과 비교합니다. strncmp는 지정한 문자열 개수만큼만 스트링을 비교하는 라이브러리 함수입니다. 이때 namefmt 변수 첫 번째 주소 기준으로 세 개 스트링이 “irq” 이면 irq_thread_enable 변수가 1로 설정되겠죠. 

IRQ Thread 이름은 setup_irq_thread 함수에서 "irq/%d-%s" 인자로 kthread_create 함수를 호출할 때 지정한다고 배웠죠? 다음 5번째 줄 코드를 봐주세요. setup_irq_thread 함수에서 지정한 "irq/%d-%s" 가 __kthread_create_on_node 함수의 namefmt 인자로 전달되는 것입니다. 그래서 이 앞 세 개의 스트링이 “irq”인지 비교하는 코드를 작성한 것입니다.  
1 static int
2 setup_irq_thread(struct irqaction *new, unsigned int irq, bool secondary)
3 {
//...
4 if (!secondary) {
5 t = kthread_create(irq_thread, new, "irq/%d-%s", irq,  // <<-[1]
6    new->name);

이제 디버깅 정보를 출력하는 13번째 줄 코드를 볼 차례입니다.
13+    if (irq_thread_enable) {
14+        void *irq_threadfn = (void*)threadfn;
15+        
16+        printk("[+] irq_thread handler: %pS caller:(%pS) \n", 
17+ irq_threadfn, (void *)__builtin_return_address(0)); 
18+        dump_stack();
19+ }

13번째 줄부터 19번째 줄까지 코드는irq_thread_enable 지역변수가 1이면 수행합니다. irq_thread_enable 변수가 1이면 뭘 의미할까요? 쓰레드 이름이 “irq”로 시작하니 IRQ Thread를 생성하려는 조건입니다. 14번째 줄 코드에서는 IRQ Thread 쓰레드 핸들 함수 포인터를 저장하고 있는 threadfn을 irq_threadfn 포인터에 캐스팅합니다. threadfn에는 irq_thread 함수 주소를 지정하고 있습니다. 16번째 줄 코드는 IRQ Thread 핸들 함수와 자신을 호출한 함수 정보를 출력합니다. 18번째 줄 코드는 콜스택을 출력하는 dump_stack 함수를 호출합니다.

이렇게 코드를 입력하고 커널 빌드를 완료한 후 라즈베리안에 커널 이미지를 설치해야겠죠? 이후 라즈베리파이를 리부팅 시키고 커널 로그(/var/log/kern.log)을 열어보면 다음과 같은 정보를 확인할 수 있습니다.

아래 로그를 차근차근 분석해볼까요?
1  [0.722882] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
2  [0.722892] mmc-bcm2835 3f300000.mmc: DMA channel allocated
3  [0.722933] [+] process_name: irq/%d-%s caller:(kthread_create_on_node+0x30/0x38) 
4  [0.722947] [+] irq_thread handler: irq_thread+0x0/0x20c
 caller:(kthread_create_on_node+0x30/0x38) 
5  [0.722958] CPU: 0 PID: 31 Comm: kworker/0:1 Not tainted 4.14.39-v7+ #15
6  [0.722962] Hardware name: BCM2835
7  [0.722980] Workqueue: events deferred_probe_work_func
8  [0.723006] (unwind_backtrace) from [<8010c21c>] (show_stack+0x20/0x24)
9  [0.723022] (show_stack) from (dump_stack+0xc8/0x10c)
10 [0.723039] (dump_stack) from (__kthread_create_on_node+0x1c4/0x1e0)
11 [0.723055] (__kthread_create_on_node) from (kthread_create_on_node+0x30/0x38)
12 [0.723070] (kthread_create_on_node) from (setup_irq_thread+0x54/0xe4)
13 [0.723086] (setup_irq_thread) from (__setup_irq+0x260/0x730)
14 [0.723101] (__setup_irq) from (request_threaded_irq+0xec/0x160)
15 [0.723118] (request_threaded_irq) from (devm_request_threaded_irq+0x78/0xcc)
16 [0.723140] (devm_request_threaded_irq) from (bcm2835_mmc_probe+0x514/0x644)
17 [0.723159] (bcm2835_mmc_probe) from (platform_drv_probe+0x60/0xc0)
18 [0.723176] (platform_drv_probe) from (driver_probe_device+0x244/0x2f8)
19 [0.723193] (driver_probe_device) from (__device_attach_driver+0xa8/0xdc)
20 [0.723210] (__device_attach_driver) from (bus_for_each_drv+0x70/0xa4)
21 [0.723228] (bus_for_each_drv) from (__device_attach+0xc0/0x124)
22 [0.723245] (__device_attach) from (device_initial_probe+0x1c/0x20)
23 [0.723261] (device_initial_probe) from (bus_probe_device+0x94/0x9c)
24 [0.723278] (bus_probe_device) from (deferred_probe_work_func+0x68/0x150)
25 [0.723296] (deferred_probe_work_func) from (process_one_work+0x224/0x518)
26 [0.723317] (process_one_work) from (worker_thread+0x60/0x5f0)
27 [0.723333] (worker_thread) from (kthread+0x144/0x174)
28 [0.723348] (kthread) from (ret_from_fork+0x14/0x28)

먼저 커널 쓰레드 이름과 쓰레드 핸들 함수를 분석하겠습니다.
3  [0.722933] [+] process_name: irq/%d-%s caller:(kthread_create_on_node+0x30/0x38) 
4  [0.722947] [+] irq_thread handler: irq_thread+0x0/0x20c  caller:(kthread_create_on_node+0x30/0x38) 

쓰레드 이름은 irq/%d-%s 이고 자신을 호출한 함수가 kthread_create_on_node+0x30이네요. IRQ Thread 쓰레드 핸들 함수는 irq_thread란 정보를 알 수 있습니다.

다음엔 이 함수가 어느 프로세스에서 실행됐는지 확인해 봐야겠죠. PID가 31인 kworker/0:1란 워커쓰레드가 CPU0에서 수행됐음을 알 수 있습니다.
5  [0.722958] CPU: 0 PID: 31 Comm: kworker/0:1 Not tainted 4.14.39-v7+ #15
6  [0.722962] Hardware name: BCM2835

이번에는 콜스택을 살펴볼 차례입니다. platform_drv_probe 함수에서 bcm2835_mmc_probe 함수를 호출하고 있습니다. 이 정보로 부팅 도중에 IRQ Thread를 설정한다고 유추할 수 있겠네요. 보통 드라이버에서 짠 코드의 함수 이름에 probe가 보이면 부팅 도중 한 번 실행합니다.
11 [0.723055] (__kthread_create_on_node) from (kthread_create_on_node+0x30/0x38)
12 [0.723070] (kthread_create_on_node) from (setup_irq_thread+0x54/0xe4)
13 [0.723086] (setup_irq_thread) from (__setup_irq+0x260/0x730)
14 [0.723101] (__setup_irq) from (request_threaded_irq+0xec/0x160)
15 [0.723118] (request_threaded_irq) from (devm_request_threaded_irq+0x78/0xcc)
16 [0.723140] (devm_request_threaded_irq) from (bcm2835_mmc_probe+0x514/0x644)
17 [0.723159] (bcm2835_mmc_probe) from (platform_drv_probe+0x60/0xc0)
18 [0.723176] (platform_drv_probe) from (driver_probe_device+0x244/0x2f8)

이후 그동안 우리가 열심히 분석한 함수들이 보입니다. request_threaded_irq 함수로 출발해서 __kthread_create_on_node 함수까지 실행하고 있습니다. kthread_create 매크로 함수 대신 실제 kthread_create_on_node 함수가 실행한다는 점도 확인할 수 있습니다.

여기까지 IRQ Thread를 생성하는 흐름을 점검했습니다. request_threaded_irq 함수를 호출하면 __kthread_create_on_node까지 호출돼서 IRQ Thread를 생성하는 것이죠. 이제 여러분이 어느 리눅스 시스템에서도 만나는 “irq/92-mmc1”과 같은 IRQ Thread가 어떤 방식으로 생성되는지 배웠습니다. 다음 절에서는 IRQ Thread가 어떻게 실행하는지 점검해보겠습니다.
태그 : , , , , ,
트랙백(0)핑백(3)덧글(0)

[라즈베리파이][리눅스커널] IRQ Thread는 언제 생성할까?[1] #CS [라즈베리파이]인터럽트후반부


IRQ Thread를 생성하기 위해서는 request_threaded_irq 을 호출하면 IRQ Thread가 생성된다고 설명해 드렸습니다. 사실 request_threaded_irq을 호출할 때 IRQ Thread가 생성되는 것은 아니고 다음 흐름에서  __kthread_create_on_node 함수가 실행할 때 생성됩니다.









우리는 커널 쓰레드를 생성할 때 kthread_create 함수를 호출한다고 배웠죠. IRQ Thread도 이 kthread_create 함수를 호출해서 생성합니다. 이로 IRQ Thread도 커널 쓰레드의 한 종류라고 유추할 수 있겠네요.

request_threaded_irq 부터 __kthread_create_on_node 함수까지 IRQ Thread를 어떻게 생성하는지 코드를 함께 살펴볼까요? 이를 위해 우선 인터럽트 핸들러를 설정하는 코드를 확인할 필요가 있습니다. 어떤 인터럽트 핸들러를 설정하는 코드를 봐야 할까요? 당연히 IRQ Thread를 생성하는 인터럽트 핸들러 코드를 봐야겠죠.

이전에 확인했다 싶히 라즈베리안에서는 "irq/92-mmc1" IRQ Thread를 확인할 수 있습니다. 
root@raspberrypi:/home/pi/dev_raspberrian# ps –ely | grep irq
S   UID   PID  PPID  C PRI  NI   RSS    SZ WCHAN  TTY          TIME CMD
S     0    65     2  0   9   -     0     0 irq_th ?        00:00:00 irq/92-mmc1

92번 인터럽트 핸들러와 해당 IRQ Thread를 설정하는 코드를 함께 분석하겠습니다. 
[drivers/mmc/host/bcm2835-mmc.c]
1 static int bcm2835_mmc_add_host(struct bcm2835_host *host)
2 {
3 struct mmc_host *mmc = host->mmc;
4 struct device *dev = mmc->parent;
//...
5 bcm2835_mmc_init(host, 0);
6 ret = devm_request_threaded_irq(dev, host->irq, bcm2835_mmc_irq,
7 bcm2835_mmc_thread_irq, IRQF_SHARED,
8 mmc_hostname(mmc), host); 

위 코드를 보면 request_threaded_irq 함수 대신 낯설게 보이는 devm_request_threaded_irq 함수로 IRQ Thread를 설정합니다. 다른 설정을 하는 함수 같아 보이기도 하는데요. 다음 코드와 같이 devm_request_threaded_irq 함수에서 request_threaded_irq 함수를 호출합니다.
1 int devm_request_threaded_irq(struct device *dev, unsigned int irq,
2       irq_handler_t handler, irq_handler_t thread_fn,
3       unsigned long irqflags, const char *devname,
4       void *dev_id)
5 {
6 struct irq_devres *dr;
7 int rc;
8
//...
9
10 rc = request_threaded_irq(irq, handler, thread_fn, irqflags, devname,
11   dev_id);

devm_request_threaded_irq 함수는 인터럽트 설정 정보를 디바이스 드라이버에서 체계적으로 관리하는 코드 빼고는 request_threaded_irq 함수와 같은 역할을 수행합니다. IRQ Thread 관점으로 devm_request_threaded_irq 함수를 호출하면 request_threaded_irq 함수가 실행된다고 봐도 무방합니다.

아래 코드에서 devm_request_threaded_irq 에서 호출하는request_threaded_irq 함수는 어디서 많이 본 함수 같지 않나요? 맞습니다. 인터럽트 핸들러를 등록할 때 호출하는 request_irq 함수에서 request_threaded_irq 함수를 호출했죠.  
static inline int __must_check
request_irq(unsigned int irq, irq_handler_t handler, unsigned long flags,
    const char *name, void *dev)
{
return request_threaded_irq(irq, handler, NULL, flags, name, dev);
}

이번에 request_threaded_irq 함수에 전달하는 인자가 약간 다른 것 같습니다.
6 ret = devm_request_threaded_irq(dev, host->irq, bcm2835_mmc_irq,
7 bcm2835_mmc_thread_irq, IRQF_SHARED,
8 mmc_hostname(mmc), host); 

6번째 줄을 보면 bcm2835_mmc_irq 함수를 인터럽트 핸들러로 등록합니다. 이 함수는 92번 “mmc1” 인터럽트가 발생하면 호출되는 함수죠. 

7번째 줄 코드를 보면 request_threaded_irq 함수 세 번째 인자로 bcm2835_mmc_thread_irq 함수를 전달합니다. 이 함수를 IRQ Thread 핸들러라고 합니다. IRQ Thread가 실행될 때 호출되는 핸들러 함수입니다.  

조금 더 이해를 돕기 위해 request_threaded_irq 함수의 선언부를 보면 세 번째 인자로 irq_handler_t thread_fn가 선언돼 있습니다. 두 번째 인자는 인터럽트 핸들러 함수입니다.
[include/linux/interrupt.h]
extern int __must_check
request_threaded_irq(unsigned int irq, irq_handler_t handler,
     irq_handler_t thread_fn,
     unsigned long flags, const char *name, void *dev);

thread_fn 이란 함수 포인터에 bcm2835_mmc_thread_irq 이란 IRQ Thread 핸들러 함수를 등록하는 것입니다.
이를 알기 쉬운 코드 형식으로 표현하면 아래와 같이 각각 인자를 다음과 같이 등록합니다.
인터럽트 번호    irq    host->irq
인터럽트 핸들러    handler    bcm2835_mmc_irq
IRQ Thread 핸들러 thread_fn  bcm2835_mmc_thread_irq

인터럽트가 발생했을 때 인터럽트 컨택스트에서 수행하는 인터럽트 핸들러는 bcm2835_mmc_irq 이고 “irq/92-mmc1” IRQ Thread에서 실행하는 핸들러 함수는 bcm2835_mmc_thread_irq 라고 볼 수 있습니다. 

이제 bcm2835_mmc_thread_irq 핸들러를 등록하고 “irq/92-mmc1”이란 IRQ Thread를 생성하는 흐름을 살펴보겠습니다. 우선 request_threaded_irq 함수부터 살펴보겠습니다.
1 int request_threaded_irq(unsigned int irq, irq_handler_t handler,
2   irq_handler_t thread_fn, unsigned long irqflags,
3   const char *devname, void *dev_id)
4 {
5  struct irqaction *action;
6  struct irq_desc *desc;
7  int retval;
//…
8 action = kzalloc(sizeof(struct irqaction), GFP_KERNEL);
//…
9  action->handler = handler;
10  action->thread_fn = thread_fn; // <<--[1]
11  action->flags = irqflags;
12  action->name = devname;
13  action->dev_id = dev_id;
14 
15  chip_bus_lock(desc);
16  retval = __setup_irq(irq, desc, action); // <--[2]

10번째 줄 [1] 코드를 보면 thread_fn 포인터를 action->thread_fn에 등록합니다. bcm2835_mmc_thread_irq 함수가 irq_handler_t thread_fn란 파라미터로 전달됩니다.
10  action->thread_fn = thread_fn; 
11  action->flags = irqflags;
12  action->name = devname;
13  action->dev_id = dev_id;

action란 포인터 타입 지역 변수는 struct irqaction 구조체로 선언됐습니다.
이 변수는 8번째 줄 코드와 같이 메모리 할당을 받은 다음에 9번째와 13번째 줄 코드와 같이 인터럽트 핸들러와 IRQ Thread 핸들러 정보를 저장하죠.

이 변수는 나중에 인터럽트 디스크립터의 action이란 멤버에 저장됩니다. 다음 struct irq_desc 구조체를 참고하세요.
struct irq_desc {
struct irq_common_data irq_common_data;
//...
struct irqaction *action; /* IRQ action list */

여기까지 설정한 인자들을 Trace32로 확인하면 다음과 같이 확인할 수 있습니다. 각 멤버들에 대한 설명은 주석문을 참고하세요.
(struct irq_desc *) (struct irq_desc*)0xB008B300
...
    (struct irqaction *) action = 0xBB4E6E40  
      (irq_handler_t) handler = 0x8061EC00 = bcm2835_mmc_irq, // 인터럽트 핸들러
      (void *) dev_id = 0xBB47B010  // 인터럽트 핸들러 핸들
      (void *) percpu_dev_id = 0x0 = ,
      (struct irqaction *) next = 0x0 = ,
      (irq_handler_t) thread_fn = 0x8061DCC4 = bcm2835_mmc_thread_irq, // IRQ Thread 핸들러
      (struct task_struct *) thread = 0xBB516CC0 // “irq/92-mmc1” IRQ Thread의 태스크 디스크립터
      (struct irqaction *) secondary = 0x0 = ,
      (unsigned int) irq = 92, // 인터럽트 번호

16번째 줄 [2] 번 코드를 보면 __setup_irq 함수를 호출합니다.
16  retval = __setup_irq(irq, desc, action);

여기까지는 인터럽트 핸들러를 등록하는 동작과 똑같습니다. 그런데 __setup_irq 함수 코드를 조금 더 살펴보면 Thread IRQ로 설정할 때만 동작하는 코드를 볼 수 있습니다. __setup_irq 코드를 같이 분석해볼까요?
1 static int
2 __setup_irq(unsigned int irq, struct irq_desc *desc, struct irqaction *new)
3 {
4 struct irqaction *old, **old_ptr;
5 unsigned long flags, thread_mask = 0;
//...
6 nested = irq_settings_is_nested_thread(desc);
//...
7 if (new->thread_fn && !nested) {  
8 ret = setup_irq_thread(new, irq, false);
9 if (ret)
10 goto out_mput;

우선 __setup_irq 함수에 전달되는 파라미터는 아래와 같습니다.
irq 인터럽트 번호
desc 인터럽트 디스크립터
new 인터럽트 디스크립터의 action 멤버(struct irq_desc->action)
 
여섯 번째 줄 코드를 보면 두 가지 조건을 점검합니다. (struct irqaction *) 타입 구조체인 new->thead_fn 멤버에 함수 포인터가 등록됐거나 nested 변수가 0일 경우에 setup_irq_thread 함수를 호출합니다. 
6 if (new->thread_fn && !nested) {  
7 ret = setup_irq_thread(new, irq, false);

nested 변수는 현재 설정하는 IRQ Thread가 nested 타입인지 점검합니다. 이 기능을 쓸 경우 nested 변수가 1이 되거든요. nested 변수를 읽어 오는 다음 코드를 눈여겨보세요.
6 nested = irq_settings_is_nested_thread(desc);
여기서 new->thead_fn 로 bcm2835_mmc_thread_irq 함수가 IRQ_Thread 핸들러로 등록됐고 nested 변수가 0이면 7번째 줄 코드가 실행되게 되겠죠.

이번에는 IRQ Thread를 생성하는 setup_irq_thread 함수를 분석할 차례입니다.
1 static int
2 setup_irq_thread(struct irqaction *new, unsigned int irq, bool secondary)
3 {
4 struct task_struct *t;
5 struct sched_param param = {
6 .sched_priority = MAX_USER_RT_PRIO/2,
7 };
8
9 if (!secondary) {
10 t = kthread_create(irq_thread, new, "irq/%d-%s", irq,  // <<-[1]
11    new->name);
12 } else {
13 t = kthread_create(irq_thread, new, "irq/%d-s-%s", irq,
14    new->name);
15 param.sched_priority -= 1;
16 }

위 코드를 보면 별 특이한 점은 없고 kthread_create 함수를 호출해서 커널 쓰레드를 생성할 뿐이죠. 

먼저 10번째 줄 [1] 코드를 볼까요? 코드를 보니irq_thread란 IRQ Thread를 제어하는 함수와 함께 "irq/%d-%s"란 이름으로 IRQ Thread를 생성합니다. 
9 t = kthread_create(irq_thread, new, "irq/%d-%s", irq,   
10    new->name);

여기서 irq는 인터럽트 번호, new->name은 인터럽트 이름이 되겠죠. 그런데 ftrace 로그를 봐도 92번 인터럽트는 이름이 mmc1이란 사실을 알 수 있습니다.
kworker/u8:2-1310  [000] d.h.  2208.183670: irq_handler_entry: irq=92 name=mmc1
kworker/u8:2-1310  [000] d.h.  2208.183673: bcm2835_mmc_irq <-__handle_irq_event_percpu
kworker/u8:2-1310  [000] d.h.  2208.183714: irq_handler_exit: irq=92 ret=handled

이 정보를 참고하면 “irq=92 name=mmc1” 인터럽트의 IRQ Thread 이름은 “irq/92-mmc1”라는 점을 유추할 수 있습니다. 

여기서 kthread_create 함수에 전달하는 두 번째 파라미터는 (struct irqaction *)new입니다. 이는 커널 쓰레드가 생성되면 쓰레드 핸들 함수로 전달됩니다. IRQ Thread인 경우 irq_thread 함수가 되겠죠. 이때 커널 쓰레드 핸들을 (struct irqaction *)new 변수로 등록한다는 점 기억하세요.
1 static int irq_thread(void *data)
2 {
3 struct callback_head on_exit_work;
4 struct irqaction *action = data;

결국 IRQ Thread가 수행할 때 irq_thread 함수가 실행하는데 이 함수 인자로 void 타입 data 포인터를 전달합니다. 이 포인터를 struct irqaction * 타입으로 캐스팅하는 것이지요.

이 과정을 정리하면 다음 다이어그램으로 설명할 수 있겠네요.

 







“irq/92-mmc1” IRQ Thread는 언제 실행될까요? 92번 인터럽트가 발생하면 해당 인터럽트 핸들러가 IRQ Thread를 실행할 지 결정합니다. 만약 아예 92번 인터럽트가 발생하지 않으면 IRQ Thread는 실행할 필요가 없는 것이지요.
태그 : , , , , , , , ,
트랙백(0)핑백(3)덧글(0)

[리눅스][커널] 커널 크래시 분석은 왜 중요할까? [Crash]Troubleshooting!!


커널 크래시 분석을 잘하는 게 왜 중요할까요? 너무 당연한 질문인가요? 사실 세상에 너무 당연한 질문은 없습니다. 어쩌면 너무 당연한 질문에 답하려고 고민하다가 많은 걸 깨닫는 경우가 많은 것 같습니다.

여러분이 리눅스 드라이버를 개발하거나 새로운 리눅스 커널 버전을 포팅했다고 가정하겠습니다. 그런데 안타깝게도 부팅 도중 아래와 같은 로그를 출력하는 커널 크래시가 100% 발생하고 있습니다. 어떻게 분석해야 할지 몰라 하루 꼬박 밤을 새웠습니다. 참 이럴 때 난감하죠. 
[ 0.986578] Kernel panic - not syncing: VFS: Unable to mount root fs on unknown-block(0,0)
[ 0.986589] CPU: 0 PID: 1 Comm: swapper Not tainted 3.18.20 #1
[ 0.986610] [<c0013260>] (unwind_backtrace) from [<c0011440>] (show_stack+0x10/0x14)
[ 0.986624] [<c0011440>] (show_stack) from [<c05a68b4>] (panic+0xf0/0x2dc)
[ 0.986640] [<c05a68b4>] (panic) from [<c083c164>] (mount_block_root+0x26c/0x2b0)
[ 0.986655] [<c083c164>] (mount_block_root) from [<c083c37c>] (prepare_namespace+0x88/0x1ac)
[ 0.986668] [<c083c37c>] (prepare_namespace) from [<c083bdac>] (kernel_init_freeable+0x16c/0x1b0)
[ 0.986681] [<c083bdac>] (kernel_init_freeable) from [<c05a5d6c>] (kernel_init+0x8/0xe0)
[ 0.986693] [<c05a5d6c>] (kernel_init) from [<c000dda0>] (ret_from_fork+0x14/0x34)
[ 1.982696] Rebooting in 5 seconds..

그런데 어떤 동료가 산신령 같이 나타나서 같이 분석을 시작합니다. 이것은 rootfs 파일 시스템 마운트를 못해서 발생한 문제라고 하네요. 그리고 꼼꼼히 로그를 같이 보면서 파티션 마운트가 제대로 됐는지 부트 디바이스가 제대로 동작하는지 점검 후 문제가 해결됐습니다. 그러면 여러분 기분은 어떨까요? (아 조금 어려운 용어 “파티션 마운트”, “부트 디바이스”, “rootfs”가 보이죠? 이번 장 마지막에 친절히 설명했으니 참고하세요.)

그 동료에게 참 고맙게 생각하겠죠. 흠, 그런데 전 약간 다릅니다. 물론 이 동료에게 감사 표현을 할 것이 분명하죠. 이런 문제를 해결 못한 저를 엄청 자책할 겁니다. 앞으로 비슷한 커널 크래시가 나오면 바로 해결할 수 있도록 열심히 준비하면서 말이죠. 


일단 이 동료는 커널 크래시 문제를 해결했습니다. 다시 반복하자면 어떤 문제를 해결했죠. 임베디드 리눅스 개발자에게 문제 해결 능력은 가장 중요한 실무 역량입니다. 모든 회사가 애타게 찾는 개발자는 문제 해결 능력이 있는 개발자입니다. 문제 해결 능력이 있는 개발자를 당연히 실력 있다고 봐야 겠죠. 그런데 문제 해결을 하기 위한 첫걸음은 문제를 정확히 분석하는 능력입니다. 대부분 로그를 분석하는 과정에 답이 있는 경우가 많거든요. 실력 있는 개발자가 되기 위해서 커널 크래시 분석 능력이 키우는 게 중요합니다. 

리눅스 커뮤니티
그런데 가끔 바로 문제 해결을 못 할 때도 있습니다. 예를 들어 리눅스 버전을 새롭게 업그레이드했는데 커널 크래시가 발생할 경우죠. 콜스택 모두 우리 눈에 낯선 함수입니다. 이 경우 어떻게 해야 할까요? 

이럴 때 너무 자신을 자책하지 마세요. 리눅스 커널은 수 많은 서브 시스템으로 이루어져 있어 소스를 볼 수 있는 범위가 넓습니다. 그래서 모든 커널 코드를 잘 알기 힘듭니다. 그래서 리눅스 커널에는 분야별로 전문적으로 코드 리뷰를 하는 메인테이너가 있습니다. 우선 아래와 같은 정보를 포함해서 정밀히 분석해야 합니다. 
- 크래시가 발생한 정확한 코드 위치와 그 이유 
- 프로세스 이름 
- 인터럽트 컨택스트 여부 
- ftrace log 상세 분석 

이렇게 정밀하게 분석을 한 다음 리눅스 커뮤니티에 업로드를 하면 되죠. 리눅스 커널 메일링 리스트에 공유하면 좋습니다. 리눅스 커널은 강력한 커뮤니티가 큰 강점이라고 알려져 있죠. 그런데, 커널 로그만 복사해서 버그를 알리면 제대로 도움을 받을 수 있을까요? 프로세스 이름, 정확히 크래시가 난 코드와 함수 위치, 문제가 발생한 재현 경로를 자세히 올려야 도움을 받을 가능성이 높습니다. 그래서 커널 크래시 분석 능력이 중요합니다. 

효율적인 업무 진행
가끔 주말 동안 스트레스 테스트를 디바이스에 돌릴 경우가 있습니다. 안드로이드에서 몽키 테스트라고 하죠. 실제 유저가 디바이스를 사용하듯이 테스트 시나리오를 만들어 신뢰성 테스트를 하는 것입니다. 그런데 보드 20대 중에 10대가 커널 크래시를 맞으면 이 때 어떤 방식으로 일을 하는 게 효율적일까요? 10개의 코어 덤프를 리눅스 커널 커뮤니티나 벅질라 이슈에 올려야 할까요? 10개의 코어 덤프를 올리는 일도 보통 오래 시간이 걸리는 일이 아니죠. 10개의 코어 덤프를 크래시 유틸리티로 자세히 분석하면 커널 크래시의 원인은 2~3개로 좁혀지는 경우가 많습니다.

커널 크래시가 발생하는 패턴을 생각해 볼 필요가 있습니다. 우리는 보통 문제가 발생한 코드에서 바로 커널 크래시가 발생할 것이라 예상할 때가 있어요. 정말 문제 코드에서 딱 크래시가 발생하면 얼마나 좋을까요? 사실 그렇지 않습니다. 원인은 하나 인데 다양한 로그로 커널 크래시가 발생할 수 있습니다. 가장 대표적인 예가 슬랩 메모리를 누군가 깨 먹는 경우입니다. 아니면 특정 디바이스에서만 커널 크래시가 발생하는 경우도 있습니다. 갑자기 다양한 커널 로그로 랜덤하게 크래시가 발생하면 정말 죽을 맛이죠. 이럴 때 정밀하게 커널 크래시 디버깅을 하면 그 범인을 잡을 수 있습니다.

프로젝트 마감에 큰 걸림돌
프로젝트 마감이 내일인데 커널 크래시가 발생하면 여러분들은 기분은 어떨까요? 제품 출시에 걸림돌이 되는 가장 큰 이슈는 커널 크래시입니다. 사소한 버그는 첫 제품 출시 후 잡자고 고객사를 설득할 수 있습니다. 그런데 커널 크래시를 고객사에게 출시 후에 잡겠다고 협의를 할 수 있을까요? 실현 불가능한 현실이죠. 이렇게 프로젝트 막바지에 가끔 임베디드 리눅스 개발자들은 이 문제를 해결하기 전에 집에 못 가는 짜증나는 경험이 생각 날 겁니다.

저 같은 경우엔 예전에 어느 매니저님께서 담요와 베개를 갖고 제 옆에 오셨던 악몽이 되살아 나는군요. 이렇게 말씀하시면서요. “이 문제 해결하기 전까지 집에 못가.” 물론 그 당시 열심히 크래시 디버깅을 해서 문제의 원인을 잡아 집에 들어는 갔습니다.

커널 크래시 디버깅을 통한 학습
커널 디버깅을 하면 할수록 리눅스 커널과 디바이스 실력이 빨리 향상됩니다. 커널 크래시 디버깅을 잘하면 리눅스 커널 개발 능력이 업그레이드 되기 때문입니다. 리눅스 커뮤니티나 주위 고수들 중에 커널 크래시 디버깅을 잘 못하는 개발자를 본 적이 없습니다.

가끔은 커널 크래시 디버깅을 잘하는 개발자를 폄하하는 분도 만난 적이 있습니다. “커널 디버깅 툴(crash utility, Trace32, ftrace)을 잘 쓸 뿐이다.”라고 말이죠. 맞습니다. 리눅스 커널 고수들 정말 디버깅 툴 잘 씁니다. 그런데 리눅스 커널에 대한 깊은 이해와 커널 자료구조에 익숙하지 않고 절대 커널 크래시 디버깅을 능숙하게 할 수 없습니다.

#커널 크래시 디버깅 및 TroubleShooting
태그 : , , , , ,
트랙백(0)핑백(1)덧글(0)

라즈베리안 설정 과정 라즈베리파이_꿀팁

1. 무선랜을 연결합니다. 네트워크 연결이 안돼 있으면 apt-get update 명령어를 제대로 실행 못합니다.

2.  다음 명령어로 패키지를 업데이트합니다.
apt-get update
apt-get upgrade

apt-get upgrade 명령어는 apt-get update를 통해서 확인한 패키지들의 최신 버전에 따라서 패키지들의 버전을 업그레이드 해주는 명령어입니다.
apt-get upgrade 명령어가 실행 완료까지는 5분 정도 시간이 걸립니다.

3. 한글 폰트를 설치합니다
apt-get install ibus
apt-get install ibus-hangul
apt-get ttf-unfonts-core

4. 키보드 설정을 합니다. 아래 링크를 참고하세요
http://rousalome.egloos.com/9975967


SD Formatter 4.0 프로그램을 이용하여 SD카드를 포맷합니다. 내컴퓨터에서 직접 포맷을 하면 SD 카드 포멧이 잘 안됩니다.
http://rousalome.egloos.com/9978204
트랙백(0)덧글(0)

[라즈베리파이] sd 카드 포멧 라즈베리파이_꿀팁

SD Formatter 4.0 프로그램을 이용하여 SD카드를 포맷합니다. 내컴퓨터에서 직접 포맷을 하면 SD 카드 포멧이 잘 안됩니다.
아래 링크에 담겨 있는 SD 카드 포멧 방법을 참고하세요.
https://kocoafab.cc/tutorial/view/299
트랙백(0)덧글(0)

[라즈베리파이][리눅스커널] 인터럽트 벡터: 스택 푸시 [라즈베리파이][커널]인터럽트

#리눅스 커널: 인터럽트

인터럽트가 발생했을 때 구동 중인 프로세스의 레지스터가 스택 메모리 공간에 푸쉬된다고 설명했습니다. 이번에 실제 Trace32 프로그램으로 스택 메모리 덤프를 확인해 보겠습니다. 

아래 콜스택은 ret_fast_syscall 함수에서 시작해서 do_fsync 함수 방향으로 호출하여 account_group_exec_runtime까지 실행하고 있는 흐름입니다.
-000|account_group_exec_runtime(inline)
-000|update_curr()
-001|check_spread(inline)
-001|put_prev_entity()
-002|put_prev_task_fair()
-003|pick_next_task_rt(inline)
-003|pick_next_task_rt()
-004|pick_next_task(inline)
-004|__schedule()
-005|arch_local_irq_disable(inline)
-005|preempt_schedule_irq()
-006|svc_preempt(asm)
-007|__irq_svc(asm)
 -->|exception
-008|blk_flush_plug_list()
-009|current_thread_info(inline)
-009|blk_finish_plug()
-010|ext4_writepages()
-011|__filemap_fdatawrite_range()
-012|filemap_write_and_wait_range()
-013|ext4_sync_file()
-014|vfs_fsync()
-015|fdput(inline)
-015|do_fsync()
-016|ret_fast_syscall(asm)

여기서 7번 콜스택에 __irq_svc 란 인터럽트 벡터 함수가 보이죠? 이를 어떻게 해석할까요? 인터럽트가 발생했다고 봐야겠죠.

조금 더 자세히 살펴보면 ret_fast_syscall -- blk_flush_plug_list 사이 콜스택 흐름으로 동작하고 있었는데 blk_flush_plug_list 함수 실행 도중 인터럽트가 발생해서 __irq_svc란 인터럽트 벡터가 실행된 거죠. 이후 인터럽트 처리를 위한 서브 루틴이 실행 중이었습니다. 이제 어떤 로그에서도 __irq_svc를 보면 편하게 분석할 수 있겠죠?

그럼 위 콜스택에서 인터럽트 벡터인 __irq_svc 함수가 호출된 시점의 스택 메모리 주소 0xCE4F9D84로 이동해서 스택 덤프를 확인하면 아래 화살표와 같이 스택에 푸쉬된 레지스터를 확인할 수 있습니다. 
[명령어: d.v %symbol.l 0xCE4F9D80]
________address||value_______|symbol
NSD:CE4F9D80| 0x20070013
NSD:CE4F9D84| 0xFFFFFFFF   
NSD:CE4F9D88| 0xCE4F9DE4
NSD:CE4F9D8C| 0xC0FF97B4   \\vmlinux\Global\__irq_svc+0x74
NSD:CE4F9D90| 0xCE4F8000
NSD:CE4F9D94| 0xCE4F8000
NSD:CE4F9D98| 0xCE4F9DAC
NSD:CE4F9D9C| 0xC0FF4E2C   \\vmlinux\sched/core\preempt_schedule_irq+0x50
NSD:CE4F9DA0| 0xC039B9DC   \\vmlinux\blk-core\blk_flush_plug_list+0x1A4
NSD:CE4F9DA4| 0xC039B9E0   \\vmlinux\blk-core\blk_flush_plug_list+0x1A8
NSD:CE4F9DA8| 0x1           
NSD:CE4F9DAC| 0xC0FF97D8   \\vmlinux\Global\svc_preempt+0x8
NSD:CE4F9DB0| 0x0           // <<--[1] R0   
NSD:CE4F9DB4| 0xCECC72B4   // <<--[2] R1   
NSD:CE4F9DB8| 0x1           // <<--[3] R2         
NSD:CE4F9DBC| 0x0           // <<--[4] R3
NSD:CE4F9DC0| 0xCE4F9E00   // <<--[5] R4
NSD:CE4F9DC4| 0xEAD60A60   // <<--[6] R5
NSD:CE4F9DC8| 0x1           // <<--[7] R6
NSD:CE4F9DCC| 0xCE4F9E00   //<<--[8] R7 
NSD:CE4F9DD0| 0x0            //<<--[9] R8
NSD:CE4F9DD4| 0x60070013   // <<--[10] R9
NSD:CE4F9DD8| 0xCE4F8000   // <<--[11] R10
NSD:CE4F9DDC| 0x1           // <<--[12] R11
NSD:CE4F9DE0| 0x60070093   // <<--[13] R12
NSD:CE4F9DE4| 0xCE4F9E00  // <<--[14] R13, 스택 주소
NSD:CE4F9DE8| 0xC039B9DC \\vmlinux\blk-core\blk_flush_plug_list+0x1A4//[15]R14
NSD:CE4F9DEC| 0xC039B9E0   \\vmlinux\blk-core\blk_flush_plug_list+0x1A8//[16]PC
NSD:CE4F9DF0| 0x20070013
NSD:CE4F9DF4| 0xFFFFFFFF

위 메모리 덤프를 보면 0x4c 공간만큼 스택 공간을 할당한 다음에 실행 중인 레지스터를 r0부터 pc까지 스택에 저장하고 있습니다. 이 레지스터들은 인터럽트를 처리하고 난 다음에 다시 이전에 실행 중인 프로세스가 다시 읽습니다. 이후 어떤 동작을 할까요? 당연히 인터럽트가 발생해서 멈췄던 코드 다음부터 실행하는 겁니다. 

인터럽트 벡터를 어셈블리로 분석하는 것은 매우 어려운 도전입니다. 잘 이해가 안 갈 수도 있어요. 저도 처음에 잘 머리에 들어오지 않았거든요. 하지만 몇 번 메모리에 레지스터가 쌓이는 동작을 그리면 프로세스 정보를 저장하는 동작이 더 오랫동안 남을 겁니다.

이제 인터럽트 벡터에서 프로세스 레지스터를 저장하고 서브 루틴을 실행하는 코드까지 확인했으니 다음 장에선 인터럽트 핸들러를 처리하는 흐름을 배워 볼게요
태그 : , , , , , , , , ,
트랙백(0)핑백(12)덧글(0)

[라즈베리파이][리눅스커널] 인터럽트 벡터 분석 [라즈베리파이][커널]인터럽트

"인터럽트 핸들러는 언제 호출할까요?"라고 누군가 물어보면 인터럽트가 발생할 때 호출한다고 대답할 수 있습니다. "그럼 인터럽트가 발생하면 가장 먼저 어떤 코드가 실행되죠?"라고 어떤 분이 질문하면 어떻게 대답할 수 있을까요? 그동안 "인터럽트가 발생하면 실행하는 코드를 멈추고 실행 정보를 저장한다"라고 배웠습니다. 그럼 실행 중인 정보가 뭘까요? 이 정보를 어떻게 저장할까요? 이 의문을 풀기 위해선 인터럽트 벡터의 어셈블리 코드를 분석해야 합니다. 

인터럽트 벡터 코드가 실행되면 우선 인터럽트에 대한 예외 처리를 합니다. 인터럽트는 하드웨어와 가장 가까운 동작이기 때문에 쓰레기 인터럽트값이 올라올 수 있거든요. 이에 대한 예외처리입니다. 이 동작은 5.3.3 장에서 더 다룰 예정이니 참고하시고요. 

이후 해당 인터럽트에 대한 인터럽트 디스크립터를 읽어옵니다. 인터럽트 디스크립터는 읽어 오는 이유는 해당 인터럽트에 대한 상세 정보(핸들러, 인터럽트 번호)가 담겨 있기 때문입니다. 이 정보를 참고해서 인터럽트 핸들러가 호출됩니다. 

인터럽트 벡터 분석하기
인터럽트 벡터는 언제 등록할까요? 부팅 과정에 등록합니다. 아래가 핵심코드인데 프로세스가 유저 모드로 동작 중 인터럽트가 발생하면 __irq_usr가 인터럽트 벡터로 실행되고 커널 모드에서는 __irq_svc가 실행됩니다. 아래 코드는 리눅스 커널보다 ARM 프로세스와 더 연관이 깊습니다. 이번엔 인터럽트 벡터와 연관된 코드 중심으로 살펴보겠습니다. 
[arch/arm/kernel/entry-armv.S]
/*
 * Interrupt dispatcher
 */
vector_stub irq, IRQ_MODE, 4

.long __irq_usr @  0  (USR_26 / USR_32)
.long __irq_invalid @  1  (FIQ_26 / FIQ_32)
.long __irq_invalid @  2  (IRQ_26 / IRQ_32)
.long __irq_svc @  3  (SVC_26 / SVC_32)
.long __irq_invalid @  4

이후 인터럽트가 발생하면 ARM supervisor 모드에서는 __irq_svc, ARM user 모드에서는 __irq_usr 벡터로 점프합니다. 참고로 커널 코드는 ARM supervisor 모드 그리고 유저 레벨 프로세스는 ARM user 모드에서 실행된다는 점 기억하세요. 그럼 이제 인터럽트 벡터 세부 동작을 어셈블리 코드로 분석하겠습니다.

__irq_svc 코드 리뷰
.

807a2a20 <__irq_svc>:
807a2a20: e24dd04c sub sp, sp, #76 ; 0x4c // <<--[1]
807a2a24: e31d0004 tst sp, #4
807a2a28: 024dd004 subeq sp, sp, #4
807a2a2c: e88d1ffe stm sp,{r1, r2, r3, r4, r5, r6, r7, r8, r9, sl, fp, ip}// <<--[2]
807a2a30: e8900038 ldm r0, {r3, r4, r5}
//.. 생략..
807a2a5c: e3a0147f mov r1, #2130706432 ; 0x7f000000
807a2a60: e5891008 str r1, [r9, #8]
807a2a64: e58d004c str r0, [sp, #76] ; 0x4c // <<--[3]
807a2a68: ebe93147 bl 801eef8c <trace_hardirqs_off>
807a2a6c: e59f1024 ldr r1, [pc, #36] ; 807a2a98 <__irq_svc+0x78> // <<--[4]
807a2a70: e1a0000d mov r0, sp
807a2a74: e28fe000 add lr, pc, #0
807a2a78: e591f000 ldr pc, [r1]   // <<--[5]
807a2a7c: ebe930e3 bl 801eee10 <trace_hardirqs_on>
807a2a80: e59d104c ldr r1, [sp, #76] ; 0x4c  
807a2a84: e5891008 str r1, [r9, #8]

[1] 코드를 먼저 보겠습니다.
sub    sp, sp, #76 ; 0x4c

여기서 sp는 현재 실행 중인 스택 주소를 뜻합니다. sub은 뺄셈 연산을 하는 ARM 명령어입니다. 즉 현재 스택 주소를 0x4C만큼 빼는 연산입니다. 그냥 스택 주소를 0x4C만큼 빼는 동작에 무슨 의미가 있는지 의문을 품을 수 있습니다. 이는 스택 공간을 0x4C 바이트만큼 확보하는 동작입니다. 이전 장에서 스택은 높은 주소에서 낮은 주소로 방향으로 자란다고 했습니다. 그래서 0x4C만큼 스택 주소를 빼는 겁니다. 만약 반대로 스택이 낮은 주소에서 높은 주소로 자라면 당연히 스택 주소에서 0x4C만큼 더해야 합니다. 그럼 왜 스택 공간을 확보할까요? 이는 스택 공간에 현재 실행 중인 프로세스의 레지스터를 저장기 위해서 입니다.

[2][3] 코드를 보겠습니다.
807a2a2c: e88d1ffe stm sp,{r1, r2, r3, r4, r5, r6, r7, r8, r9, sl, fp, ip}// <<--[2]
807a2a30: e8900038 ldm r0, {r3, r4, r5}
//.. 생략..
807a2a5c: e3a0147f mov r1, #2130706432 ; 0x7f000000
807a2a60: e5891008 str r1, [r9, #8]
807a2a64: e58d004c str r0, [sp, #76] ; 0x4c // <<--[3]

우선 stm이란 명령어가 보입니다. 좀 낯선 ARM 어셈블리이지만 자주 쓰는 명령어입니다. stm #A {#B, #C} 란 명령어는 #A가 위치한 메모리 공간에 #B와 #C를 저장하는 동작입니다. 그럼 [2] 코드를 해석하면 스택이 위치한 메모리 공간에 r1부터 ip 레지스터까지 저장하는 것입니다. [3] 코드까지 실행하면  레지스터를 스택에 저장합니다.

그동안 “인터럽트가 발생하면 현재 실행 중인 프로세스 정보를 저장한다”란 내용이 이 코드에 담겨 있습니다. 즉 인터럽트가 발생하기 전에 수행됐던 레지스터를 스택 공간에 저장하는 겁니다.

이제 [4] 코드를 봅시다.
807a2a6c: e59f1024 ldr r1, [pc, #36] ; 807a2a98 

ldr이란 명령어는 대략 ”ldr r1, [#A]”이란 형식으로 쓰입니다. #A 메모리 공간에 있는 값을 r1에 로딩한다는 의미입니다. 이 명령어는 ARM에서 가장 많이 쓰이는 명령어니 알고 있으면 편하게 코드를 읽을 수 있습니다. ldr 명령어를 분석하면 80705398 메모리 공간에 있는 80c089ac 값을 r1으로 로딩하는 동작입니다. 그런데 80c089ac 주소에는 handle_arch_irq란 전역 변수가 있습니다. 

다음은 [5] 코드입니다.
80705378: e591f000 ldr pc, [r1] 

이 코드에서 handle_arch_irq란 전역 변수 위치가 가르키는 함수를 프로그램 카운터 즉 실행 주소로 저장합니다. 여기서 bcm2836_arm_irqchip_handle_irq 함수를 호출합니다. 그 이유는 부팅할 때 handle_arch_irq란 변수에 bcm2836_arm_irqchip_handle_irq 함수 주소를 저장하기 때문입니다. 다음 코드와 같이 bcm2836(브로드컴 칩셋 이름)의 인터럽트 콘트롤러를 초기화한 후 설정합니다.
static int __init bcm2836_arm_irqchip_l1_intc_of_init(struct device_node *node,
      struct device_node *parent)
{
//...
bcm2836_arm_irqchip_smp_init();

set_handle_irq(bcm2836_arm_irqchip_handle_irq);

대부분 ARM을 탑재한 칩셋은 gic_handle_irq함수를 handle_arch_irq로 등록해서 인터럽트 벡터 이후 인터럽트를 처리합니다만 라즈베리파이가 쓰는 bcm2836 칩셋(SoC: System On Chip)는 인터럽트 처리를 칩셋 구조에 맞게 설계한 것으로 보입니다. 이렇게 인터럽트를 처리하는 방식은 칩셋을 설계한 개발자에 따라 다릅니다.

ARM user 모드일 때 실행되는 __irq_usr 인터럽트 벡터도 비슷하게 동작하니 시간 될 때 __irq_usr 코드도 한번 살펴보세요.

라즈베리안 리눅스 커널은 인터럽트 벡터에서 현재 동작 중인 프로세스의 스택을 푸시하고 bcm2836_arm_irqchip_handle_irq 함수를 호출하여 리눅스 커널이 인터럽트 처리를 시작합니다. 그런데 어셈블코드에서 설명했던 스택 메모리에 레지스터 정보가 실제 어떻게 저장되는지 궁금하지 않으세요? 이 정보를 파악하면 더 이해가 빠르니 한번 확인해 볼게요.
태그 : , , , , ,
트랙백(0)덧글(0)

[라즈베리파이][리눅스커널] 인터럽트 컨택스트에서 스케쥴링을 하면? [라즈베리파이][커널]인터럽트


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

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

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

인터럽트 컨택스트에서 다음 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()) // <<--[3]
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)// [2]
[<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)
[<c0212d04>] (__irq_svc) from [<c02a2e30>] (ktime_get_ts64+0x1c8/0x200) // [1]
[<c02a2e30>] (ktime_get_ts64) from [<c032d4a0>] (poll_select_set_timeout+0x60/0xa8)
[<c032d4a0>] (poll_select_set_timeout) from [<c032df64>] (SyS_select+0xa8/0x118)
[<c032df64>] (SyS_select) from [<c020e8e0>] (ret_fast_syscall+0x0/0x48)

이제까지 배운 내용을 활용해서 위 로그를 분석해보겠습니다.

[1] 로그에서 보이는 __irq_svc는 인터럽트 벡터 함수입니다. 
[<c0214dc0>] (handle_IPI) from [<c0208930>] (gic_handle_irq+0x64/0x68)
[<c0208930>] (gic_handle_irq) from [<c0212d04>] (__irq_svc+0x44/0x5c)
[<c0212d04>] (__irq_svc) from [<c02a2e30>] (ktime_get_ts64+0x1c8/0x200) //<<--[1]

이 정보로 인터럽트가 발생했다고 판단할 수 있습니다. 이후 gic_handle_irq와handle_IPI 순서로 인터럽트를 처리하는 함수가 호출합니다. 

자 그럼 [1] 코드 흐름을 우리는 어떻게 해석할 수 있죠? 인터럽트가 발생해서 인터럽트 벡터가 실행됐으므로 당연히 인터럽트 컨택스트라 할 수 있습니다. 

[2] 로그에서 뮤텍스락을 획득합니다. 
[<c02492f0>] (warn_slowpath_fmt) from [<c086a3f8>] (mutex_lock_nested+0x3a0/0x3e8)
[<c086a3f8>] (mutex_lock_nested) from [<c0294d08>](irq_find_host+0x20/0x9c) // <<--[2]

마지막 [3] 로그를 보겠습니다. 
DEBUG_LOCKS_WARN_ON(in_interrupt()) //<<--[3]

현재 인터럽트 컨택스트인지 확인하여 커널 패닉을 유발합니다. 다음 [3] 로그와 같이 in_interrupt() 함수가 true를 리턴하니 DEBUG_LOCKS_WARN_ON 란 WARN() 함수가 실행됩니다. 참고로 WARN() 매크로 함수가 실행하면 그 시점의 콜스택을 뿌려줍니다.

이번 시간에는 인터럽트 컨택스트에 대해서 알아봤습니다. 인터럽트 컨택스트는 인터럽트가 발생 후 인터럽트를 처리하는 코드 흐름이라 빨리 코드를 실행해야 합니다. 이를 알려주는 매크로 함수는 in_interrupt() 입니다.

다음에는 인터럽트 핸들러는 언제 어떻게 호출하는지 알아보겠습니다.
태그 : , , , , ,
트랙백(0)핑백(12)덧글(0)

[라즈베리파이][리눅스커널] in_interrupt() 함수란 [라즈베리파이][커널]인터럽트


in_interrupt() 함수란
리눅스 커널이 실행할 때 수많은 함수가 각자 서로를 호출합니다. 어떤 함수는 프로세스 컨택스트에서 실행(커널 쓰레드)되는데 대부분 함수는 인터럽트 컨택스트, 즉 인터럽트 처리하는 도중 호출될 수 있습니다. 만약 현재 실행하는 코드가 인터럽트를 처리 중이면 더 빨리 처리해야겠죠? 

인터럽트 서비스 루틴은 실행 중인 프로세스를 멈추고 동작하므로 인터럽트 컨택스트 조건에서만 신속하게 코드를 실행시키고 싶을 때가 있습니다. 그럼 현재 실행 중인 코드가 인터럽트 컨택스트 구간인지 어떻게 알 수 있을까요? in_interrupt()란 함수가 이 정보를 알려줍니다. 

그럼 다음 패치를 함께 살펴 봅시다. 
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)
1  {
2        struct dm_region *reg, *nreg;
3
4 -       nreg = mempool_alloc(rh->region_pool, GFP_ATOMIC);
5 +       gfp_t gfp_flag = GFP_KERNEL;  
6 +       if (in_interrupt()) {   
7 +               gfp_flag = GFP_ATOMIC;
8 +       }
9 +       nreg = mempool_alloc(flush_entry_pool, gfp_flag);
10 +
11         if (unlikely(!nreg))
12                 nreg = kmalloc(sizeof(*nreg), GFP_NOIO | __GFP_NOFAIL);.

참고로 – 기호는 원래 코드이고 + 기호는 추가하는 코드이니 이점 참고하세요. 

위 코드는 __rh_alloc() 함수가 인터럽트 컨택스트 조건에서 다른 동작을 합니다.
먼저 5번 줄 코드를 봅시다. 
5 +       gfp_t gfp_flag = GFP_KERNEL;  

메모리 설정 플래그를 저장하는 지역 변수 gfp_flag를 GFP_KERNEL로 초기화합니다.  
다음은 6번 줄 코드입니다.
6 +       if (in_interrupt()) {   
7 +               gfp_flag = GFP_ATOMIC;
8 +       }

in_interrupt() 함수가 true이면 인터럽트 처리 중이므로 gfp_flag를 GFP_ATOMIC으로 설정하고 메모리를 할당합니다. GFP_ATOMIC 옵션으로 kmalloc() 함수를 호출하면 스케줄링 없이 메모리 할당합니다. 반대로 in_interrupt() 함수가 false로 리턴하면 현재 코드가 프로세스 컨택스트에서 수행 중이니 GFP_KERNEL 옵션으로 메모리를 할당합니다. 참고로 GFP_ATOMIC 옵션으로 메모리를 할당하면 프로세스는 휴면하지 않고 메모리를 할당하고, GFP_KERNEL 옵션인 경우 메모리 할당 실패 시 휴면할 수 있습니다. 

요약하면 인터럽트 처리 도중에는 빨리 메모리를 할당하는 코드입니다.

이제 in_interrupt() 함수 코드를 살펴 봅시다. 아래 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.

HARDIRQ_OFFSET(0x10000)란 매크로는 인터럽트를 처리 중이란 정보를 나타내고 HARDIRQ_MASK이란 매크로는 이 HARDIRQ_OFFSET(0x10000)이란 비트 가져오기 위한 비트 마스크입니다.

만약 어떤 값이 0x210200인데 이 값에 HARDIRQ_MASK(0x10000)와 AND 비트 연산을 하면 결괏값은 0x10000이 됩니다. 반복해서 설명을 드리면 0x10000는 HARDIRQ_OFFSET 이니 인터럽트를 처리 중이란 의미입니다.

리눅스 커널 수 많은 코드에서 비트 연산을 볼 수 있습니다. ARM 프로세스 입장에서 비트 연산자는 실행 속도가 빠르기 때문입니다. 

이제 preempt_count 코드를 조금 더 살펴 봅시다. 
static __always_inline int preempt_count(void)
{
return READ_ONCE(current_thread_info()->preempt_count);
}

current_thread_info()->preempt_count 값을 리턴하는데 이 코드를 이해하려면 current_thread_info() 코드를 살펴봐야 합니다. current_thread_info() 함수를 보겠습니다.
register unsigned long current_stack_pointer asm ("sp"); //<<-- [1]

static inline struct thread_info *current_thread_info(void)
{
return (struct thread_info *)
(current_stack_pointer & ~(THREAD_SIZE - 1)); //<<-- [2]
}

current_thread_info 함수를 눈여겨보면, [1] 코드에서 스택 주소를 sp 지역 변수로 읽어 옵니다. 여기서 “asm(“sp”)” 는 인라인 어셈블리 코드입니다. C 문법에 없는 코드인데, 리눅스 커널에선 아주 자주 호출되는 코드는 인라인 어셈블리를 씁니다. C 코드에서 어셈블리 코드를 쓰는 겁니다.

다시 [1] 코드를 보면 지역 변수를 register 타입으로 선언했습니다. 이는 sp란 지역 변수를 다른 지역 변수를 처리하듯이 스택 공간 말고 ARM 레지스터를 써서 처리하라는 의미입니다. 여기서 다른 지역 변수와 register 타입으로 선언된 지역 변수의 차이점은 뭘까요? 그 이유는 register 타입으로 지역 변수를 설정하면 더 적은 어셈블리 코드로 해당 코드를 수행할 수 있습니다. current_thread_info란 인라인 함수가 아주 많이 호출되기 때문입니다. 

이제 [2]번 코드를 봅시다.
[kernel/arch/arm/include/asm/thread_info.h]
static inline struct thread_info *current_thread_info(void)
{
return (struct thread_info *)
(current_stack_pointer & ~(THREAD_SIZE - 1)); //<<-- [2]
}

이 코드는 스택 Top 주소를 계산합니다. 이 주소에 프로세스 실행 정보가 담긴 struct thread_info 구조체의 멤버가 저장돼 있습니다.

정리하면 현재 구동 중인 함수 내에서 확인되는 스택 주소를 통해 스택 상단 Top 주소를 얻어 온 후 struct thread_info 구조체의 preempt_count 멤버에서 얻어오는 값입니다. 
위 그림 상단 낮은 주소(Top 주소)로 옆에 struct thread_info란 구조체가 볼 수 있습니다.  커널 프로세스마다 스택 Top 주소에 이 구조체 데이터를 저장합니다. 정리하면 in_interrupt()란 매크로는 현재 프로세스의 스택에 저장된 struct thread_info 구조체의 preempt_count 멤버를 읽습니다. 

이제까지 설명해 드린 내용을 실제 디바이스에서 확인해 봅시다.

아래는 코어 덤프를 로딩해서 Trace32 프로그램으로 확인한 struct thread_info 자료 구조입니다. 
(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,

참고로, 리눅스 커널에서는 커널 패닉이 발생하면 그 시점의 메모리 덤프를 받을 수 있는 기능을 지원합니다. 이 메모리 덤프를 보통 vmcore 혹은 코어 덤프라고 합니다. 

이제 코어 덤프 분석으로 돌아가면, preempt_count값은 0x00010002로 현재 프로세스가 인터럽트 컨택스트에서 실행 중임을 알 수 있습니다. 이 이유는 0x00010002 값과 10000 (HARDIRQ_OFFSET)을 AND 연산하면 결과는 1이기 때문입니다.

여기까지 잘 이해되시나요? 조금 낯선 용어들은 조금 지나면 친숙해지니 끝까지 읽어주세요. 다시 반복하면 HARDIRQ_OFFSET 란 비트는 “현재 인터럽트 처리 중”임을 나타냅니다.
 
인터럽트 처리 시작을 설정하는 HARDIRQ_OFFSET 란 비트는 어느 함수에서 설정할까요? 
코드를 조금 더 살펴보면 __irq_enter 매크로에서 HARDIRQ_OFFSET 비트를 설정하고 있습니다.

위 그림에서 보이는 __handle_domain_irq() 함수를 열어 봅시다.
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);
  }
 
  irq_exit();  // <<--
  set_irq_regs(old_regs);
  return ret;
 }

__handle_domain_irq 함수에서 인터럽트 핸들러를 호출하기 전 irq_enter란 함수를 호출합니다. 함수 이름대로 “인터럽트 처리 시작”을 나타내는 표시로 보입니다. 제 생각에 irq_enter보다 irq_context_enter로 함수 이름을 바꾸면 함수 동작을 빨리 짐작할 수 있을 것 같습니다. 해당 코드는 아래 화살표가 가르키고 있으니 잘 살펴보세요.

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)

이후 해당 인터럽트 핸들러가 호출되어 인터럽트에 대한 처리를 마친 후에 다음 함수가 호출됩니다. 자, 이제 아래 코드 흐름에서 __irq_exit란 함수가 보이죠? 이 함수에서 struct thread_info.preempt_count 멤버에서 HARDIRQ_OFFSET 비트를 해제합니다. 


바로 __irq_exit() 함수를 보겠습니다. 
#define __irq_exit()     \
  do {      \
   trace_hardirq_exit();   \
   account_irq_exit_time(current);  \
   preempt_count_sub(HARDIRQ_OFFSET); \
  } while (0) 

여기까지 HARDIRQ_OFFSET 비트를 설정하고 해제하는 흐름을 알아봤는데, 이 비트는 뭘 의미할까요? HARDIRQ_OFFSET 비트(0x10000)은 현재 코드가 인터럽트를 처리하고 있는지를 나타냅니다. 이 비트를 설정하면 “현재는 인터럽트 처리 중”, 해제하면 “현재 인터럽트 처리 중은 아님”을 알려주는 겁니다. 

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

라즈베리안(라즈베리파이)에서 in_interrupt() 함수 동작 확인
여기까지 자세히 코드를 분석 했습니다. 이제 커널 소스를 조금 수정해서 라즈베리안에서는 in_interrupt 매크로 값이 뭔지 확인하겠습니다. 손으로 코드를 입력하고 결과를 확인해야 배운 내용을 더 오랫동안 기억할 수 있습니다. 

인터럽트 핸들러에 아래 코드를 반영하고 로그를 받아보면 in_interrupt() 함수 리턴값을 볼 수 있습니다.
diff --git a/drivers/mmc/host/bcm2835-sdhost.c b/drivers/mmc/host/bcm2835-sdhost.c
index 273b1be05..5f57b3dab 100644
--- a/drivers/mmc/host/bcm2835-sdhost.c
+++ b/drivers/mmc/host/bcm2835-sdhost.c
@@ -1472,6 +1472,16 @@ static irqreturn_t bcm2835_sdhost_irq(int irq, void *dev_id)
  struct bcm2835_host *host = dev_id;
  u32 intmask;
 
+ void *stack;
+ struct thread_info *current_thread;
+
+ stack = current->stack;  // <<--[1]
+ current_thread = (struct thread_info*)stack; // <<--[2]
+
+ printk("[+] in_interrupt: 0x%08x,preempt_count = 0x%08x, stack=0x%08lx \n", 
+ (unsigned int)in_interrupt(), (unsignedint)current_thread->preempt_count, (long unsigned int)stack); // [3]
+
+
  spin_lock(&host->lock);
 
  intmask = bcm2835_sdhost_read(host, SDHSTS);

위와 같이 코드를 변경하기 전 bcm2835_sdhost_irq 함수는 다음과 같았습니다. void *stack부터 시작하는 +라고 표시한 코드를 u32 intmask; 와 spin_lock(&host->lock); 코드 사이에 추가하면 됩니다.
[drivers/mmc/host/bcm2835-sdhost.c]
static irqreturn_t bcm2835_sdhost_irq(int irq, void *dev_id)
{
irqreturn_t result = IRQ_NONE;
struct bcm2835_host *host = dev_id;
u32 intmask;
// <<--패치 코드 추가 위치
spin_lock(&host->lock);

이제 그럼 패치 코드를 리뷰해 봅시다.

[1]: 다음 코드는 현재 실행 중인 프로세스의 태스크 디스크립터 정보를 얻어옵니다.
+ stack = current->stack;

현재 실행 중인 코드에서 태스크 디스크립터 정보를 어떻게 얻어올까요? 이때 current란 매크로를 쓰면 됩니다. 이는 커널에서 제공하는 매크로인데 커널에서 자주 사용합니다. (이 세부 동작은 4장 프로세스에서 다루니 참고하세요.) struct task_struct 구조체에 stack이란 멤버에 스택 Top 주소가 저장돼 있습니다. 이 스택 Top 주소로 preempt_count 멤버 변수에 접근할 수 있습니다.

[2]: 스택 탑(Top) 주소에 struct thread_info 구조체 정보가 있다고 배웠습니다. 이 구조체로 캐스팅합니다.
+ current_thread = (struct thread_info*)stack;

[3]: in_interrupt와 struct thread_info.preempt_count 값을 출력합니다.
+ printk("[+] in_interrupt: 0x%08x,preempt_count = 0x%08x, stack=0x%08lx \n", 
+ (unsigned int)in_interrupt(), (unsignedint)current_thread->preempt_count, (long unsigned int)stack);  

위 로그를 작성하고 컴파일하면 문제없이 커널 빌드가 될 겁니다. 이후 커널 이미지를 다운로드 하고 커널 로그를 확인하면 됩니다.

커널 로그를 받아보면, in_interrupt() 함수는 현재 실행 중인 프로세스 스택에 저장된 struct thread_info->preempt_count 값에서 HARDIRQ_OFFSET 비트만 출력하기 위해 HARDIRQ_MASK로 마스킹한 결과를 리턴한다는 점을 알 수 있습니다.
[0.911605] Indeed it is in host mode hprt0 = 00021501
[1.001692] mmc1: new high speed SDIO card at address 0001
[1.037804] [+] in_interrupt: 0x00010000,preempt_count = 0x00010000, stack=0x80c00000 
[1.039271] [+] in_interrupt: 0x00010000,preempt_count = 0x00010000, stack=0x80c00000 
[1.041839] [+] in_interrupt: 0x00010000,preempt_count = 0x00010000, stack=0x80c00000 
[1.042911] mmc0: host does not support reading read-only switch, assuming write-enable
[1.044570] [+] in_interrupt: 0x00010000,preempt_count = 0x00010000, stack=0x80c00000 
[1.046503] mmc0: new high speed SDHC card at address aaaa
[1.046995] mmcblk0: mmc0:aaaa SB16G 14.8 GiB May 13 13:07:23 raspberrypi kernel:

위 로그에서 preempt_count 값은 0x00010000이고 in_interrupt 값은 0x00010000이죠? 0x00010000 값에서 HARDIRQ_OFFSET 비트 값만 뽑아서 출력한 값이 0x00010000값 입니다. “in_interrupt: 0x00010000” 이 로그의 의미는 “현재 인터럽트 처리 중”이라는 것이며 현재 코드가 인터럽트 컨택스트라는 사실을 알려줍니다. 

이렇게 코드 분석 후 패치 코드를 작성해서 실제 시스템에서 출력되는 결괏값을 확인하면 더 오랫동안 머릿속에 남습니다. 

다음에는 인터럽트 컨택스트에서 실행 시간이 오래 걸리는 코드를 입력하면 어떤 일이 발생하는지 확인해 보겠습니다.
태그 : , , , , , ,
트랙백(0)핑백(12)덧글(0)

[라즈베리파이]리눅스 커널 매크로 분석 방법 [라즈베리파이][커널]매크로분석



매크로 분석에 도움 되는 두 가지 방법을 소개합니다. 전처리 파일 추출과 바이너리 유틸리티를 활용해서 어셈블리 코드를 보는 방법입니다. 매크로를 분석할 때는 물론 평소 커널 코드 읽을 때는 이 방법을 적극적으로 활용해서 분석하기를 바랍니다. C 코드만 볼 때 보다 훨씬 효율적으로 코드를 읽을 수 있고 더 유용한 디버깅 정보를 볼 수 있거든요.

전처리 파일 추출
이번에는 전처리 코드를 추출하는 방법을 소개합니다.

보통 리눅스 커널 코드를 분석할 때 C 코드를 열어 봅니다. 그런데 C 코드를 전처리 파일과 함께 분석하면 효율적으로 리눅스 커널 코드를 읽을 수 있습니다. 그 이유는 컴파일러가 전처리 과정에서 매크로를 모두 풀어서 표현한 정보를 전처리 파일이 담고 있기 때문입니다.

그럼 리눅스 커널 코드에서 전처리 파일을 어떻게 생성할까요? 방법은 매우 간단합니다. 리눅스 커널을 빌드하는 Makefile을 다음과 같이 수정하고 빌드하면 됩니다.
diff --git a/Makefile b/Makefile
index 4a7e6df..313dbbe 100644
--- a/Makefile
+++ b/Makefile
@@ -395,6 +395,7 @@ KBUILD_CFLAGS   := -Wall -Wundef -Wstrict-prototypes -Wno-trigraphs
                   -fno-strict-aliasing -fno-common
                   -Werror-implicit-function-declaration
                   -Wno-format-security
+                  -save-temps=obj
                   -std=gnu89
 KBUILD_CPPFLAGS := -D__KERNEL__
 KBUILD_AFLAGS_KERNEL :=

위와 같이 Makefile을 수정하여 커널 빌드를 완료하면 전처리 파일이 생성됩니다. 그럼 전처리 파일은 어디에서 볼 수 있나요? 아래 명령어로 전처리 파일을 각 커널 디렉터리에서 확인할 수 있습니다.
austindh.kim@~/src/raspberry_kernel/linux$ find . -name *.i | more
./mm/.tmp_filemap.i
./mm/.tmp_dmapool.i
./mm/.tmp_highmem.i
./mm/.tmp_mmu_context.i
./mm/.tmp_slab_common.i
./mm/.tmp_readahead.i

평소 전처리 파일은 특정 폴더에 저장해 놓고 코드 분석에 활용하면 좋습니다.

바이너리 유틸리티로 어셈블리 코드 분석

라즈베리파이 github에서 크로스 컴파일 툴 체인 프로그램을 다운로드 할 수 있는데요.
다음 명령어를 입력하면 다운로드 받을 수 있습니다. 참고로 이 명령어는 라즈베리파이 커뮤니티에서 확인할 수 있어요.
git clone https://github.com/raspberrypi/tools

다운로드가 끝나면 여러 가지 폴더가 생성됩니다. 이 중에서 arm-bcm2708 하위 폴더로 이동하면 다음과 같은 바이너리 유틸리티를 확인할 수 있습니다. 디렉터리 위치는 다음과 같습니다.
[./arm-bcm2708/gcc-linaro-arm-linux-gnueabihf-raspbian/bin]

바이너리 유틸리티 프로그램 설치 방법을 설명 드리는 이유는 바이너리 유틸리티 중 arm-linux-gnueabihf-objdump를 써서 어셈블리 코드를 볼 수 있기 때문입니다. 

그럼 어셈블리 코드를 어떻게 생성할까요? 라즈베리안을 리눅스 커널을 컴파일하면 디버깅 정보가 포함된 vmlinux가 생성됩니다. 이 vmlinux를 arm-linux-gnueabihf-objdump란 바이너리 유틸리티로 실행하면 됩니다. arm-linux-gnueabihf-objdump 파일과 vmlinux을 같은 폴더에 위치시키고 다음 명령어를 입력하면, 라즈베리안 리눅스 커널 코드를 어셈블리 형태로 볼 수 있습니다.
./arm-linux-gnueabihf-objdump -S -d vmlinux  > rasberian_kernel_code.c

잠깐 여기서 리눅스 커널을 익힐 때 어셈블리 코드 분석이 얼마나 중요한지에 대해서 잠깐 말씀 드리려고해요. 그동안 리눅스 커널을 C 코드 형태로 읽었던 분이 어셈블리 명령어를 함께 분석하면 다양한 지식을 얻을 수 있습니다. 왜냐면 리눅스 커널 핵심 코드는 어셈블리 코드로 구현돼 있기 때문이죠. 사실 리눅스 커널 이론서에 있는 많은 내용은 어셈블리 코드를 분석한 결과를 요약한 것이거든요. 리눅스 커널의 핵심 개념을 제대로 이해하려면 어셈블리 명령어를 잘 알아야겠죠.

여기까지 리눅스 커널 코드를 분석하는데 유용한 두 가지 기법을 소개했습니다. 그럼 앞으로 전처리 파일과 어셈블리 코드를 활용해서 어떻게 매크로를 분석하는지 기대하세요.
태그 : , , , ,
트랙백(0)핑백(8)덧글(0)

[라즈베리파이][리눅스커널]IRQ Thread(threaded IRQ) 란 #CS [라즈베리파이]인터럽트후반부

리눅스 커널을 익히는 과정에서 만나는 걸림돌 중 하나가 어려운 용어입니다. 어려운 개념을 낯선 용어로 설명하니 이해하기 어렵죠. IRQ Thread의 의미를 알기 전에 IRQ란 용어부터 알아볼까요? IRQ는 Interrupt Request의 약자로 하드웨어에서 발생한 인터럽트를 처리 한다는 의미입니다. 조금 더 구체적으로 인터럽트 발생 후 인터럽트 핸들러까지 처리하는 흐름입니다. 

IRQ Thread란 뭘까요? 인터럽트 핸들러에서는 처리하면 오래 걸리는 일을 수행하는 프로세스입니다. 인터럽트 후반부 처리를 위한 인터럽트 처리 전용 프로세스입니다. 리눅스 커널에서는 IRQ Thread를 irq_thread라고도 합니다. 리눅스 커널 커뮤니티에서는 threaded IRQ 방식이라고도 합니다. 용어는 달라도 같은 의미입니다. 

IRQ Thread 기법은 인터럽트 후반부 처리를 IRQ Thread에서 수행하는 방식을 의미합니다. 이제 용어를 간단히 정리했으니 IRQ Thread에 대해 조금 더 알아볼게요. 

라즈베리안에서는 IRQ Thread를 어떻게 확인할 수 있을까요? ps -ely 명령어를 입력하면 프로세스 목록을 볼 수 있습니다. 
root@raspberrypi:/home/pi/dev_raspberrian# ps -ely
S   UID   PID  PPID  C PRI  NI   RSS    SZ WCHAN  TTY          TIME CMD
S     0     1     0  0  80   0  6012  6750 SyS_ep ?        00:00:02 systemd
S     0     2     0  0  80   0     0     0 kthrea ?        00:00:00 kthreadd
//...
S     0    64     2  0  70 -10     0     0 down_i ?        00:00:00 SMIO
S     0    65     2  0   9   -     0     0 irq_th ?        00:00:00 irq/92-mmc1
I     0    66     2  0  80   0     0     0 worker ?        00:00:00 kworker/0:3

위 목록에서 irq/92-mmc1가 보이죠. 이 프로세스가 IRQ Thread입니다. 커널에서 지어준 이름인데 다음 규칙에 따라 이름을 짓습니다.
"irq/인터럽트 번호-인터럽트 이름"

irq/92-mmc1프로세스는 위 규칙에 따라 어떻게 해석하면 될까요? mmc1이란 이름의 92번째 인터럽트를 처리하는 IRQ Thread라 할 수 있습니다. 라즈베리안에서는 위와 같이 1개의 IRQ Thread만 볼 수 있는데, 다른 리눅스 시스템에서는 보통 10개 이상 IRQ Thread를 확인할 수 있습니다.

이번에는 다른 리눅스 시스템에서 IRQ Thread를 확인해볼까요? 
다음 로그는 안드로이드를 탑재한 Z5 compact 제품(Snapdragon 810)의 리눅스 개발자 커뮤니티에서 공유된 로그입니다.
[출처:https://forum.xda-developers.com/z5-compact/general/9-battery-drain-overnight-97-deep-sleep-t3382145/page6]
1  root      14    2     0      0     worker_thr 0000000000 S kworker/1:0H
2  root      15    2     0      0     smpboot_th 0000000000 S migration/2
3  root      16    2     0      0     smpboot_th 0000000000 S ksoftirqd/2
//...
4  root      36    2     0      0     rescuer_th 0000000000 S rpm-smd
5  root      38    2     0      0     irq_thread 0000000000 S irq/48-cpr
6  root      39    2     0      0     irq_thread 0000000000 S irq/51-cpr
//...
7  root      199   2     0      0     irq_thread 0000000000 S irq/212-msm_dwc
//...
8  root      65    2     0      0     irq_thread 0000000000 S irq/261-msm_iom
9  root      66    2     0      0     irq_thread 0000000000 S irq/263-msm_iom
10 root      67    2     0      0     irq_thread 0000000000 S irq/261-msm_iom
11 root      68    2     0      0     irq_thread 0000000000 S irq/263-msm_iom
12 root      69    2     0      0     irq_thread 0000000000 S irq/261-msm_iom
13 root      70    2     0      0     irq_thread 0000000000 S irq/263-msm_iom
14 root      71    2     0      0     irq_thread 0000000000 S irq/261-msm_iom
15 root      72    2     0      0     irq_thread 0000000000 S irq/263-msm_iom
16 root      73    2     0      0     irq_thread 0000000000 S irq/261-msm_iom
17 root      74    2     0      0     irq_thread 0000000000 S irq/263-msm_iom
18 root      75    2     0      0     irq_thread 0000000000 S irq/261-msm_iom

ps 명령어로 출력한 전체 프로세스 중 IRQ Thread만 가려냈는데요. irq_thread 타입으로 볼드체로 표시한 프로세스가 IRQ Thread입니다. IRQ Thread가 14개나 있네요.

위 로그 중에 “irq/212-msm_dwc”란 IRQ Thread를 해석하면 msm_dwc란 이름의 212번째 인터럽트를 처리하는 IRQ Thread라고 볼 수 있겠죠. 
7 root      199   2     0      0     irq_thread 0000000000 S irq/212-msm_dwc

이렇게 상용 리눅스 시스템의 IRQ Thread 개수를 소개한 이유는 여러분이 IRQ Thread는 1개 밖에 없다고 착각할 수 있기 때문입니다. 왜냐면, 라즈베리안에서 IRQ Thread가 1개 밖에 없으니까요. 

이렇게 라즈베리안에 비해 상용 안드로이드 리눅스 디바이스에서는 IRQ Thread가 더 많은 것 같습니다. IRQ Thread가 더 많으면 더 좋은 시스템일까요? 그렇지는 않습니다. 이는 시스템에 인터럽트를 어떻게 설계하고 구성했는지에 따라 다릅니다. 

어떤 인터럽트가 발생하면 인터럽트 핸들러 이후에 실행되는 IRQ Thread가 있다는 것은 뭘 의미할까요? 해당 인터럽트가 발생하면 소프트웨어적으로 할 일이 많다고 봐야겠죠. 인터럽트가 발생했을 때 바로 해야 하는 일은 인터럽트 핸들러에서 처리하고, 조금 후 프로세스 레벨에서 해도 되는 일은 IRQ Thread에서 수행하는 것입니다.

IRQ Thread를 생성하기 위해서는 어떻게 해야 하죠? 방법은 간단합니다. 인터럽트 핸들러를 설정하는 request_irq 함수 대신 request_threaded_irq 을 호출하면 됩니다.

request_threaded_irq 함수의 원형은 다음과 같은데요. 세 번째 파라미터인 thread_fn에 IRQ Thread가 실행되면 호출할 핸들러만 지정해주면 됩니다. 그러면 커널에서 인터럽트 이름과 번호 정보를 바탕으로 IRQ Thread를 생성해 줍니다.
extern int __must_check
request_threaded_irq(unsigned int irq, irq_handler_t handler,
     irq_handler_t thread_fn,
     unsigned long flags, const char *name, void *dev);

여기서 Top Half는 인터럽트 핸들러인 handler 그리고 Bottom Half는 IRQ Thread가 수행되면 수행하는 핸들러 함수인 thread_fn 라고 할 수 있겠죠.

실제 request_threaded_irq를 호출하는 코드를 보면서 이 내용을 함께 알아볼까요? 다음 코드는 다른 리눅스 시스템에서 USB 드라이버 설정 코드입니다. 
[https://elixir.bootlin.com/linux/v4.14.30/source/drivers/usb/dwc3/gadget.c#L1927]
1 static int dwc3_gadget_start(struct usb_gadget *g,
2  struct usb_gadget_driver *driver)
3 {
4 struct dwc3 *dwc = gadget_to_dwc(g);
5 unsigned long flags;
6 int ret = 0;
7 int irq;
8
9 irq = dwc->irq_gadget;
10 ret = request_threaded_irq(irq, dwc3_interrupt, dwc3_thread_interrupt,
11 IRQF_SHARED, "dwc3", dwc->ev_buf);

인터럽트 핸들러를 설정할 때 썼던 request_irq 함수와 유사해 보이네요. 그런데 request_threaded_irq 함수도 비슷하게 인터럽트 핸들러를 등록하는 것 같습니다. request_irq를 호출할 때 같은 인자를 채우는데, request_threaded_irq는 IRQ Thread 핸들러인 dwc3_thread_interrupt 함수를 추가하는군요.

request_threaded_irq 함수 호출로 해당 인터럽트에 대한 전용 IRQ Thread가 생성됩니다. 리눅스 커널에서 이 IRQ Thread 이름을 어떻게 지을까요? 위 인터럽트 번호가 47이면  "irq/47-dwc3"이 되겠죠.

인터럽트 발생 후 dwc3_interrupt란 인터럽트 핸들러에서 인터럽트에 대한 처리를 한 다음 "irq/47-dwc3" IRQ Thread를 깨울지 결정합니다. 이후 "irq/47-dwc3" IRQ Thread가 깨어나면 dwc3_thread_interrupt 함수가 호출되는 구조죠.

해당 코드를 볼까요? dwc 인터럽트가 발생하면 dwc3_interrupt란 인터럽트 핸들러가 실행되겠죠? 다음 dwc3_interrupt 함수를 보면 바로 dwc3_check_event_buf 함수를 호출하는군요. 
[https://elixir.bootlin.com/linux/v4.14.30/source/drivers/usb/dwc3/gadget.c#L3154]
static irqreturn_t dwc3_interrupt(int irq, void *_evt)
{
struct dwc3_event_buffer *evt = _evt;
return dwc3_check_event_buf(evt);
}

dwc3_check_event_buf 함수 구현부는 다음과 같습니다.
[https://elixir.bootlin.com/linux/v4.14.30/source/drivers/usb/dwc3/gadget.c#L3107] 
1 static irqreturn_t dwc3_check_event_buf(struct dwc3_event_buffer *evt)
2 {
3 struct dwc3 *dwc = evt->dwc;
4 u32 amount;
5 u32 count;
6 u32 reg;
7
8 if (pm_runtime_suspended(dwc->dev)) {
9 pm_runtime_get(dwc->dev);
10 disable_irq_nosync(dwc->irq_gadget);
11 dwc->pending_events = true;
12 return IRQ_HANDLED;
13 }
//...
14 if (amount < count)
15 memcpy(evt->cache, evt->buf, count - amount);
16
17 dwc3_writel(dwc->regs, DWC3_GEVNTCOUNT(0), count);
18
19 return IRQ_WAKE_THREAD;
20}

위 함수를 눈여겨보면 시스템 상태에 따라 IRQ_HANDLED와 IRQ_WAKE_THREAD를 리턴합니다. 인터럽트가 발생한 후 일을 더 할 필요가 없을 때는 다음 코드와 같이 IRQ_HANDLED를 리턴합니다.
8 if (pm_runtime_suspended(dwc->dev)) {
9 pm_runtime_get(dwc->dev);
10 disable_irq_nosync(dwc->irq_gadget);
11 dwc->pending_events = true;
12 return IRQ_HANDLED;
13 }

특정 조건으로 IRQ Thread가 해당 인터럽트에 대한 처리를 더 수행해야 할 때는 IRQ_WAKE_THREAD를 리턴합니다.
17 dwc3_writel(dwc->regs, DWC3_GEVNTCOUNT(0), count);
18
19 return IRQ_WAKE_THREAD;
20}

이후 IRQ Thread가 깨어난 후 IRQ Thread 핸들러인 dwc3_thread_interrupt가 인터럽트 핸들러에서 바로 하지 못한 일을 수행합니다. 

여기까지 라즈베리안에서 실행하는 드라이버 코드는 아니지만, 다른 시스템 드라이버에서는 어떤 방식으로 request_threaded_irq을 호출했는지 간단히 리뷰했습니다. 다음 시간에는 라즈베리안에서 IRQ Thread가 어떻게 실행하는지 더 자세히 알아볼까요?
태그 : , , , , , , , , , ,
트랙백(0)핑백(3)덧글(0)

[라즈베리파이]인터럽트 후반부 처리(Bottom Half) 소개 #CS [라즈베리파이]인터럽트후반부

리눅스 커널이 인터럽트를 어떻게 처리하는지 배운 내용을 잠깐 복습해볼까요? 핵심 개념은 다음과 같습니다.
첫째, 인터럽트가 발생하면 커널은 실행 중인 프로세스를 멈추고 인터럽트 벡터를 실행해서 인터럽트 핸들러를 실행합니다.
둘째, 인터럽트 핸들러는 짧고 빨리 실행해야 합니다.
셋째, 인터럽트를 처리하는 구간이 인터럽트 컨택스트인데 이를 in_interrupt 매크로가 알려줍니다.

욕심이 지나쳐 인터럽트 핸들러에서 많은 일을 하고 싶을 때가 있습니다. 가령 유저 공간에 인터럽트가 발생한 사실을 알리거나 다른 프로세스에게 일을 시키고 싶은 경우죠. 그런데 인터럽트 핸들러에서 이런 동작을 실행하면 어떻게 될까요? 이럴 때 시스템이 아주 느려지거나 커널이 오동작 할 수 있습니다. 그래서 인터럽트 컨택스트에서 많은 일을 하는 함수를 호출하면 커널은 이를 감지하고 커널 패닉을 유발합니다. 

인터럽트 핸들러에서 많은 일을 하다가 커널 패닉이 발생하는 예를 들어 볼까요? 다음 로그는 인터럽트 핸들러 실행 도중 발생한 커널 패닉 로그입니다. 함수가 일렬로 정렬해있습니다.
[21.719319] [callstack mxt_interrupt,2449] task[InputReader]========= 
[21.719382] BUG: scheduling while atomic: InputReader/1039/0x00010001
[21.719417] (unwind_backtrace+0x0/0x144) from (dump_stack+0x20/0x24)
[21.719432] (dump_stack+0x20/0x24) from (__schedule_bug+0x50/0x5c)
[21.719444] (__schedule_bug+0x50/0x5c) from (__schedule+0x7c4/0x890)
[21.719455] (__schedule+0x7c4/0x890) from [<c0845d70>] (schedule+0x40/0x80)
[21.719468] (schedule+0x40/0x80) from [<c0843bc0>] (schedule_timeout+0x190/0x33c)
[21.719480] (schedule_timeout+0x190/0x33c) from (wait_for_common+0xb8/0x15c)
[21.719491] (wait_for_common+0xb8/0x15c) from (wait_for_completion_timeout+0x1c/0x20)
[21.719504] (wait_for_completion_timeout+0x1c/0x20) from (tegra_i2c_xfer_msg+0x380/0x958)
[21.719517] (tegra_i2c_xfer_msg+0x380/0x958) from (tegra_i2c_xfer+0x314/0x438)
[21.719531] (tegra_i2c_xfer+0x314/0x438) from (i2c_transfer+0xc4/0x128)
[21.719546] (i2c_transfer+0xc4/0x128) from (__mxt_read_reg+0x70/0xc8)
[21.719560] (__mxt_read_reg+0x70/0xc8) from (mxt_read_and_process_messages+0x58/0x1648)
[21.719572] (mxt_read_and_process_messages+0x58/0x1648) from (mxt_interrupt+0x78/0x144)
[21.719588] (mxt_interrupt+0x78/0x144) from (handle_irq_event_percpu+0x88/0x2ec)
[21.719601] (handle_irq_event_percpu+0x88/0x2ec) from (handle_irq_event+0x4c/0x6c)
[21.719614] (handle_irq_event+0x4c/0x6c) from (handle_level_irq+0xbc/0x118)
[21.719626] (handle_level_irq+0xbc/0x118) from (generic_handle_irq+0x3c/0x50)
[21.719642] (generic_handle_irq+0x3c/0x50) from (tegra_gpio_irq_handler+0xa8/0x124)
[21.719655] (tegra_gpio_irq_handler+0xa8/0x124) from (generic_handle_irq+0x3c/0x50)
[21.719669] (generic_handle_irq+0x3c/0x50) from (handle_IRQ+0x5c/0xbc)
[21.719682] (handle_IRQ+0x5c/0xbc) from (gic_handle_irq+0x34/0x68)
[21.719694] (gic_handle_irq+0x34/0x68) from (__irq_svc+0x40/0x70)

참고로 위 로그가 동작한 시스템은 엔비디아 Tegra4i SoC 디바이스입니다. 그래서 tegra가 붙은 함수들이 보이죠. 가끔 라즈베리안 이외 다른 리눅스 시스템에서 발생한 문제를 소개할게요.

로그를 꼼꼼히 분석해볼까요? 함수들이 줄 서 있는데 어느 부분 로그부터 읽어봐야 할까요? 함수들이 가장 먼저 실행된 순서로 정렬돼 있으니 가장 아랫부분 로그부터 봐야 합니다. 이제부터 5장에서 배운 내용을 떠 올리면서 로그 분석을 시작할게요.
 
가장 처음 실행된 함수 로그부터 볼게요. 인터럽트가 발생하면 인터럽트 벡터인 __irq_svc가 실행하니 인터럽트가 발생했다고 볼 수 있습니다. 인터럽트 벡터인 __irq_svc 함수부터 실행된 콜스택(함수 흐름)이니 인터럽트 컨택스트이네요. 
[21.719682] (handle_IRQ+0x5c/0xbc) from (gic_handle_irq+0x34/0x68)
[21.719694] (gic_handle_irq+0x34/0x68) from (__irq_svc+0x40/0x70)

아래 로그로 인터럽트 핸들러로 mxt_interrupt 함수가 호출됐다는 사실을 알 수 있습니다. 
[21.719572] (mxt_read_and_process_messages+0x58/0x1648) from (mxt_interrupt+0x78/0x144)
[21.719588] (mxt_interrupt+0x78/0x144) from (handle_irq_event_percpu+0x88/0x2ec)
[21.719601] (handle_irq_event_percpu+0x88/0x2ec) from (handle_irq_event+0x4c/0x6c)

인터럽트 핸들러는 __handle_irq_event_percpu 함수에서 호출한다고 배웠습니다. 그런데 위 로그에서는 handle_irq_event_percpu 함수에서 인터럽트 핸들러를 호출하네요.

그 이유는 이 로그를 출력한 시스템의 리눅스 커널 버전이 3.10.77 버전이기 때문입니다. 다음 코드를 보면 5번째 줄 코드에서 인터럽트 핸들러를 호출합니다.
[https://elixir.bootlin.com/linux/v3.10.77/source/kernel/irq/handle.c#L133]
1 irqreturn_t
2 handle_irq_event_percpu(struct irq_desc *desc, struct irqaction *action)
3 {
...
4 do {
...
5 res = action->handler(irq, action->dev_id);

다음은 커널 패닉이 발생하는 이유를 알려주는 로그입니다. 함수 흐름으로 보아 wait_for_common 함수를 호출해서 complete 함수가 수행되기를 기다리는 상황입니다. 그런데 complete 함수 호출을 안 하니 schedule_timeout 함수를 호출하는군요.
[21.719444] (__schedule_bug+0x50/0x5c) from (__schedule+0x7c4/0x890)
[21.719455] (__schedule+0x7c4/0x890) from [<c0845d70>] (schedule+0x40/0x80)
[21.719468] (schedule+0x40/0x80) from [<c0843bc0>] (schedule_timeout+0x190/0x33c)
[21.719480] (schedule_timeout+0x190/0x33c) from (wait_for_common+0xb8/0x15c)
[21.719491] (wait_for_common+0xb8/0x15c) from (wait_for_completion_timeout+0x1c/0x20)
[21.719504] (wait_for_completion_timeout+0x1c/0x20) from (tegra_i2c_xfer_msg+0x380/0x958)
[21.719517] (tegra_i2c_xfer_msg+0x380/0x958) from (tegra_i2c_xfer+0x314/0x438)

이후 __schedule -> __schedule_bug 순서로 함수를 호출합니다.

이제 커널 패닉이 발생하는 이유를 알려주는 로그를 볼 차례입니다. 인터럽트 컨택스트에서 스케줄링을 하니 커널은 이를 감지하고 커널 패닉을 유발하는 것입니다.
[21.719319] [callstack mxt_interrupt,2449] task[InputReader]========= 
[21.719382] BUG: scheduling while atomic: InputReader/1039/0x00010001

두 번째 줄 로그를 보면 InputReader는 프로세스 이름, 1039는 pid 그리고 0x00010001는 struct thread_info의 preempt_count 멤버 변수입니다. 0x00010001 값과 HARDIRQ_OFFSET(0x10000)란 매크로를 AND 연산하면 1이므로 인터럽트 컨택스트이네요.

그리고 위 로그에서 “scheduling while atomic”란 메시지가 보입니다. 여기서 atomic이란 무슨 의미일까요? 커널에서는 어떤 코드나 루틴이 실행 도중 스케줄링 되면 안 될 때 있습니다. 이를 유식한 말로 원자적 처리라고 하며 원어 그대로 atomic operation이라고 합니다. 그런데 커널에서는 인터럽트 컨택스트도 실행 도중 스케쥴링하면 안되는 atomic operation이라고 판단합니다. 그래서 이런 경고 메시지를 출력하는 것이죠. (atomic operation은 커널 동기화 장에서 자세히 다루니 이 점 참고하세요.)

정리하면 인터럽트 컨택스트에서 스케쥴링을 시도하니 커널은 이를 감지하고 커널 패닉을 유발하는 것입니다.

인터럽트가 발생하면 처리할 일이 많을 때는 어떻게 해야 할까요? 인터럽트 컨택스트에서는 빨리 일을 끝내야 하는데 말이죠. 이럴 때는 해야 할 일을 두 개로 나누면 됩니다. 빨리 처리해야 하는 일과 조금 있다가 처리해도 되는 일이죠. 임베디드 세상에선 인터럽트가 발생 후 빨리 처리해야 하는 일은 Top Half, 조금 있다가 처리해도 되는 일은 Bottom Half라고 합니다. 좀 낯선 용어죠. 그런데 사실 용어만 낯설지 그 내용은 별 게 아니에요. 우선 인터럽트 핸들러가 하는 일은 Top Half라고 할 수 있죠. Bottom Half는  인터럽트에 대한 처리를 프로세스 레벨에서 수행하는 방식입니다. 이를 인터럽트 후반부 처리라고도 합니다.

리눅스 커널에서 Bottom Half는 어떻게 구현할까요? 보통 IRQ Thread, Soft IRQ와 워크큐 기법으로 구현합니다. 인터럽트 핸들러는 일하고 있던 프로세스를 멈춘 시점인 인터럽트 컨택스트에서 실행하는데 IRQ Thread, Soft IRQ와 워크큐는 커널 쓰레드 레벨에서 실행합니다. 급하게 처리해야 할 일은 인터럽트 컨택스트 조금 후 실행해도 되는 일은 커널 쓰레드 레벨에서 처리하는 것입니다. 

인터럽트 컨택스트와 커널 쓰레드 레벨에서 어떤 코드를 동작할 때 어떤 차이점이 있을까요?
우선 인터럽트 컨택스트에서는 호출할 수 있는 함수가 제한돼 있습니다. 리눅스 커널에서는 인터럽트 컨택스트에서 많은 일을 하는 함수를 호출할 때 경고 메시지를 출력하거나 커널 패닉을 유발해서 시스템 실행을 중단시킵니다. 예를 들어 스케쥴링과 연관된 뮤텍스나 schedule 함수를 쓰면 커널은 강제로 커널 패닉을 유발합니다.

그런데 인터럽트 컨택스트에 비해 커널 쓰레드에서는 커널이 제공하는 스케쥴링을 포함한 모든 함수를 쓸 수 있습니다. 그래서 시나리오에 따라 유연하게 코드를 설계할 수 있습니다.

예를 들어 인터럽트가 발생했을 때 이를 유저 공간에 알리고 싶을 경우가 있습니다. 안드로이드  디바이스 같은 경우에 터치를 입력하면 발생하는 인터럽트를 uevent로 유저 공간에 알릴 수 있죠. 이런 동작은 IRQ Thread에서 동작하도록 코드를 구현해야 합니다.

이번 장에서는 리눅스 커널이 Bottom Half을 처리하는 대표적인 기법인 IRQ Thread와 Soft IRQ에 대해 살펴봅니다. 워크큐는 워크큐를 다루는 장에서 살펴볼 예정입니다. 세 가지 기법은 인터럽트가 발생하고 나면 처리하는 방식이 조금씩 다르지만 인터럽트 핸들러에서 해야 할 일을 나눈다는 점은 같습니다. 
 
이 세가지 기법의 특징이 뭔지 잠깐 알아볼까요?
IRQ Thread(threaded IRQ)
인터럽트를 처리하는 전용 IRQ Thread에서 인터럽트 후속 처리를 합니다. 만약 rasp란 24번 인터럽트가 있으면 “irq/24-rasp”란 IRQ Thread가 24번 인터럽트를 전담해서 처리합니다.
Soft IRQ
인터럽트 핸들러가 실행이 끝나면 이때 일을 시작합니다. 인터럽트 핸들러에서 하지 못한 처리를 하다가 실행 시간이 오래 걸리면 ksoftirqd란 프로세스로 스케쥴링되고 이 ksoftirqd란 프로세스에서 나머지 인터럽트 후반부 잔업을 처리하는 구조입니다.
워크큐
인터럽트 핸들러가 실행될 때 워크를 워크큐에 큐잉하고 프로세스 레벨의 워커 쓰레드에서 인터럽트 후속처리를 하는 방식입니다.

인터럽트를 처리하는 드라이버를 작성할 때 위 세 가지 중 어느 기법을 선택할지는 드라이버 담당자의 몫입니다. 인터럽트 발생 빈도와 이를 처리하는 시나리오에 따라 위 세 가지 기법을 적절히 조합해서 드라이버 코드를 작성해야 합니다. 이를 위해서 인터럽트를 시스템에서 처리하는 방식과 인터럽트 발생 빈도를 알아야 합니다. 사실, 디바이스 드라이버나 시스템 전반을 설계하는 개발자는 인터럽트가 발생하면 소프트웨어적으로 이를 어떻게 설계할지 많은 고민을 합니다. 이런 설계를 잘하려면 우선 이 기법들은 잘 알고 있어야겠죠.

예를 들어 유저가 터치 화면을 입력하면 발생하는 인터럽트는 IRQ Thread나 워크큐를 써서 처리하면 되고, 1초에 수백 번 이상 발생하는 인터럽트를 예정된 시간 내에 처리해야 하는 실행 속도에 민감한 시나리오에서는 Soft IRQ 기법을 써야 합니다.
태그 : , , , , , , , , , , ,
트랙백(0)핑백(3)덧글(0)

[라즈베리파이] 인터럽트 디버깅 - in_interrupt #CS [라즈베리파이][커널]인터럽트

in_interrupt 함수는 현재 구동 중인 프로세스 스택 Top 주소에 위치한 current_thread_info()->preempt_count 멤버이며 인터럽트 서비스 루틴이 실행되기 전 __irq_enter 함수에서 HARDIRQ_OFFSET를 더하고 인터럽트 서비스 루틴이 종료되면 해제합니다.

이제 커널 소스를 조금 수정해서 라즈베리안에서는 in_interrupt 매크로 값이 뭔지 확인하겠습니다. 

인터럽트 핸들러에 아래 코드를 반영하고 로그를 받아보면 in_interrupt() 함수 리턴값을 볼 수 있습니다.
diff --git a/drivers/mmc/host/bcm2835-sdhost.c b/drivers/mmc/host/bcm2835-sdhost.c
index 273b1be05..5f57b3dab 100644
--- a/drivers/mmc/host/bcm2835-sdhost.c
+++ b/drivers/mmc/host/bcm2835-sdhost.c
@@ -1472,6 +1472,16 @@ static irqreturn_t bcm2835_sdhost_irq(int irq, void *dev_id)
  struct bcm2835_host *host = dev_id;
  u32 intmask;
 
+ void *stack;
+ struct thread_info *current_thread;
+
+ stack = current->stack;  //<<--[1]
+ current_thread = (struct thread_info*)stack; //<<--[2]
+
+ printk("[+] in_interrupt: 0x%08x,preempt_count = 0x%08x, stack=0x%08lx \n", 
+ (unsigned int)in_interrupt(), (unsignedint)current_thread->preempt_count, (long unsigned int)stack); //<<--[3]
+
+
  spin_lock(&host->lock);
 
  intmask = bcm2835_sdhost_read(host, SDHSTS);

위와 같이 코드를 변경하기 전 bcm2835_sdhost_irq 함수는 다음과 같았어요. void *stack부터 시작하는 +라고 표시한 코드를 u32 intmask; 와 spin_lock(&host->lock); 코드 사이에 추가하면 됩니다.
[drivers/mmc/host/bcm2835-sdhost.c]
static irqreturn_t bcm2835_sdhost_irq(int irq, void *dev_id)
{
irqreturn_t result = IRQ_NONE;
struct bcm2835_host *host = dev_id;
u32 intmask;
// <<--패치 코드 추가 위치
spin_lock(&host->lock);

이제 그럼 패치 코드를 찬찬히 리뷰해볼까요?
[1]: 아래 코드는 현재 실행 중인 프로세스의 태스크 디스크립터 정보를 얻어옵니다.
+ stack = current->stack;

그럼 현재 실행 중인 코드에서 태스크 디스크립터 정보를 어떻게 얻어올까요? 이때 current란 매크로를 쓰면 됩니다. 이는 커널에서 제공하는 매크로인데 커널에서 자주 사용합니다. struct task_struct 구조체에 stack이란 멤버에 스택 Top 주소가 저장돼 있거든요. 이 스택 Top 주소로 preempt_count 멤버 변수에 접근할 수 있습니다.

[2]: 스택 탑(Top) 주소에 struct thread_info 정보가 있다고 배웠죠? 이 구조체로 캐스팅합니다.
+ current_thread = (struct thread_info*)stack;
 
[3]: in_interrupt와 struct thread_info.preempt_count 값을 출력합니다.
+ printk("[+] in_interrupt: 0x%08x,preempt_count = 0x%08x, stack=0x%08lx \n", 
+ (unsigned int)in_interrupt(), (unsignedint)current_thread->preempt_count, (long unsigned int)stack);  

커널 로그를 받아보면, in_interrupt() 함수는 현재 실행 중인 프로세스 스택에 저장된 struct thread_info->preempt_count 값에서 HARDIRQ_OFFSET 비트만 출력하기 위해 HARDIRQ_MASK로 마스킹한 결과를 리턴한다는 것을 알 수 있습니다.
[0.911605] Indeed it is in host mode hprt0 = 00021501
[1.001692] mmc1: new high speed SDIO card at address 0001
[1.037804] [+] in_interrupt: 0x00010000,preempt_count = 0x00010000, stack=0x80c00000 
[1.039271] [+] in_interrupt: 0x00010000,preempt_count = 0x00010000, stack=0x80c00000 
[1.041839] [+] in_interrupt: 0x00010000,preempt_count = 0x00010000, stack=0x80c00000 
[1.042911] mmc0: host does not support reading read-only switch, assuming write-enable
[1.044570] [+] in_interrupt: 0x00010000,preempt_count = 0x00010000, stack=0x80c00000 
[1.046503] mmc0: new high speed SDHC card at address aaaa
[1.046995] mmcblk0: mmc0:aaaa SB16G 14.8 GiB May 13 13:07:23 raspberrypi kernel:
 
위 로그에서 preempt_count 값은 0x00010000이고 in_interrupt 값은 0x00010000이죠? 0x00010000 값에서 HARDIRQ_OFFSET 비트 값만 뽑아서 출력한 값이 0x00010000값 인데요. “in_interrupt: 0x00010000” 이 로그의 의미는 “현재 인터럽트 처리 중”이라는 것이며 현재 코드가 인터럽트 컨택스트라는 사실을 알려줍니다. 

이렇게 코드 분석 후 패치 코드를 작성해서 실제 시스템에서 출력되는 결괏값을 확인하면 더 오랫동안 머릿속에 남습니다.

태그 : , , , , ,
트랙백(0)덧글(0)

[Linux][Kernel] 커널 크래시란 [Crash]Troubleshooting!!


커널 패닉이란 말을 들어본 적이 있나요? 혹시 여러분이 임베디드 리눅스 개발자면 몇 번 쯤은 들어봤을 겁니다. 하지만, 리눅스를 자주 안 쓰거나 리눅스를 학습 용도로 쓰시는 분들에겐 단어가 낯설게 들릴수도 있죠. 

여러분들은 대부분 컴퓨터나 노트북을 윈도 운영체제로 쓰실 겁니다. 그런데 혹시 컴퓨터를 오래 쓰다가 블루 스크린을 본 적이 있나요? 밝은 파란색 배경 화면에 흰색으로 이상한 경고 문구가 떠있죠. 이 때 컴퓨터는 아무런 동작을 안합니다. 이런 화면을 처음 봤을 때 어땠나요? 좀 짜증나지 않았나요? 전 예전 처음 이 블루 스크린을 봤을 때 엄청 당황했었어요. 왜냐면 “전원을 다시 키면 부팅은 할까?”, “혹시 컴퓨터에 저장된 자료가 날아가는 건 아닌가”? 이런 걱정을 했죠. 정말 뭔가 컴퓨터에 큰 고장이 난 것 같았어요. 

이렇게 윈도 운영체제에서 뜨는 블루 스크린은 리눅스 운영 체제에서는 발생하지 않을까요? 다들 아시겠지만 윈도 운영체제에서 뜨는 블루 스크린이 리눅스에서도 있습니다. 대신 리눅스 운영체제에서는 검은색 배경에 흰색 문구를 띄웁니다. 이를 보통 커널 패닉이라고 합니다. 개발자들은 커널 크래시라고도 말하죠.

그럼 커널 크래시는 왜 발생할까요? 그 이유에 대해서 찬찬히 살펴볼게요.  혹시 소프트웨어 공학에서 ASSERT란 단어 들어 보신적 있나요? 이해를 돕기 위해서 간단한 코드를 소개 할게요. 아래 코드를 눈 여겨 보면 param이란 포인터가 NULL이 아니면 void 타입의 파라미터를 task란 지역 변수로 캐스팅합니다. 그런데 param이란 포인터가 NULL이면 ASSERT를 유발하죠.
void proc_func_ptr(void *param)
{
       struct task_struct *task;
if (!param) 
ASSERT(1);
    else
task = (struct task_struct*)param;

리눅스 커널에서는 ASSERT 대신 BUG() 혹은 panic() 란 함수를 씁니다. 보통 소프트웨어적으로 심각한 오류 상태라 더 이상 실행할 수 없다고 판단 할 때 호출 합니다. 그럼 만약 param 이란 포인터가 널일 때 아래 if 구문이 없으면 어떻게 동작할까요? 이후 구문에서 Data Abort로 익셉션이 발생 할 겁니다.
void proc_func_ptr(void *param)
{
        struct task_struct *task;
if (!param) 
BUG();
    else
task = (struct task_struct*)param;

그럼 비슷한 유형의 리눅스 커널 코드를 잠깐볼까요? 아래 함수를 보면 BUG_ON()이란 함수가 보이죠.
[drivers/clk/tegra/clk-tegra20.c]
1 static unsigned long tegra20_clk_measure_input_freq(void)
2 {
3 u32 osc_ctrl = readl_relaxed(clk_base + OSC_CTRL);
4 u32 auto_clk_control = osc_ctrl & OSC_CTRL_OSC_FREQ_MASK;
5 u32 pll_ref_div = osc_ctrl & OSC_CTRL_PLL_REF_DIV_MASK;
6 unsigned long input_freq;
7
8 switch (auto_clk_control) {
9 case OSC_CTRL_OSC_FREQ_12MHZ:
10 BUG_ON(pll_ref_div != OSC_CTRL_PLL_REF_DIV_1);
11 input_freq = 12000000;
12 break;
13 case OSC_CTRL_OSC_FREQ_13MHZ:
14 BUG_ON(pll_ref_div != OSC_CTRL_PLL_REF_DIV_1);
15 input_freq = 13000000;
16 break;
// .. 생략 ..
17 default:
18 pr_err("Unexpected clock autodetect value %d",
19        auto_clk_control);
20 BUG();
21 return 0;
22 }

위 코드는 nVidia Tegra SoC에서 클락을 제어하는 코드인데요. 
10번과 14번째 줄 코드를 보면 pll_ref_div != OSC_CTRL_PLL_REF_DIV_1, pll_ref_div != OSC_CTRL_PLL_REF_DIV_1 조건이 보이죠? 만약 pll_ref_div !=OSC_CTRL_PLL_REF_DIV_1 조건을 만족하면 결과는 1이기 때문에 BUG_ON(1)이 호출되고 결국 BUG()함수가 수행되어 커널 크래시를 발생합니다. 이 코드를 해석하면 이 조건이 시스템이 치명적인 결함이 생길 위험이 크다고 판단하는 것입니다.

또한 8번 줄의 auto_clk_control 값이 switch~case문에서 정의된 case에서 처리안되고 default가 수행되면 커널 패닉을 유발시킵니다. 이 조건도 시스템을 더 이상 구동시킬 수 없는 상태로 보고 있습니다.

자, 그럼 다음 코드를 같이 살펴볼까요?
[init/do_mounts.c]
1 void __init mount_block_root(char *name, int flags)
2 {
// .. 생략..
3 printk_all_partitions();
4 #ifdef CONFIG_DEBUG_BLOCK_EXT_DEVT
5 printk("DEBUG_BLOCK_EXT_DEVT is enabled, you need to specify "
6        "explicit textual name for \"root=\" boot option.\n");
7 #endif
8 panic("VFS: Unable to mount root fs on %s", b);

8번 줄의 panic이란 함수가 보이죠? 부팅 도중 root 파일 시스템을 마운트를 못했을 때 panic() 함수를 호출해서 커널 패닉을 유발합니다. 그럼 왜 커널 크래시를 유발할까요? root 파일 시스템이 마운트 안되면 시스템 부팅 과정에서 계속 에러가 발생할 겁니다. root 파일 시스템이 마운트 안된 사실을 모르고 계속 시스템 에러를 잡는 삽질을 할 가능성이 높죠.  그래서 커널 크래시를 유발하고 우선 root 파일 시스템 마운트를 하라고 알려주는 겁니다. 참고로  root 파일 시스템을 통해 시스템 기본 설정에 연관된 init rc파일들을 읽습니다. 


이렇게 리눅스 커널 코드를 살펴보면 이런 panic과 BUG 코드가 지뢰 밭처럼 깔려 있는데요. 이런 코드를 추가한 이유는 뭘까요? 왜 강제로 커널 크래시를 유발해서 짜증나게 할까요? 이 이유에 대해서 조금 더 살펴볼께요.

#커널 크래시 디버깅 및 TroubleShooting
태그 : , , , , , , , ,
트랙백(0)핑백(1)덧글(0)

[라즈베리파이] 인터럽트 디버깅 - proc/interrupts #CS [라즈베리파이][커널]인터럽트


새로운 리눅스 시스템을 접했을 때 인터럽트의 개수와 종류를 바로 파악하려면 proc 파일 시스템을 활용할 필요가 있습니다.

그럼 라즈베리안에서 인터럽트 종류와 개수를 바로 알려면 어떤 명령어를 입력해야 할까요? 우선 리눅스 커널 proc 파일 시스템이 알려주는 인터럽트 정보(/proc/interrupts)를 활용할 필요가 있습니다. 그럼 이 정보부터 같이 점검하기 위해 다음 명령어를 입력해볼까요?
root@raspberrypi:/home/pi# cat /proc/interrupts

그럼 다음과 같은 정보를 볼 수 있습니다.

           CPU0       CPU1       CPU2       CPU3       

16:          0          0          0          0 bcm2836-timer   0 Edge      arch_timer

17:     129951    132772     128401     128648 bcm2836-timer   1 Edge      arch_timer

21:          0          0          0          0 bcm2836-pmu     9 Edge      arm-pmu

23:       1264          0          0          0 ARMCTRL-level   1 Edge      3f00b880.mailbox

24:       1710          0          0          0 ARMCTRL-level   2 Edge      VCHIQ doorbell

46:        137          0          0          0 ARMCTRL-level  48 Edge      bcm2708_fb dma

48:          0          0          0          0 ARMCTRL-level  50 Edge      DMA IRQ

50:          0          0          0          0 ARMCTRL-level  52 Edge      DMA IRQ

51:       2375          0          0          0 ARMCTRL-level  53 Edge      DMA IRQ

54:      32325          0          0          0 ARMCTRL-level  56 Edge      DMA IRQ

59:          0          0          0          0 ARMCTRL-level  61 Edge      bcm2835-auxirq

62:    1355025          0          0          0 ARMCTRL-level  64 Edge      dwc_otg, dwc_otg_pcd, dwc_otg_hcd:usb1

86:       8025          0          0          0 ARMCTRL-level  88 Edge      mmc0

87:       5121          0          0          0 ARMCTRL-level  89 Edge      uart-pl011

92:      52579          0          0          0 ARMCTRL-level  94 Edge      mmc1FIQ:


위 로그에서 보이는 여러 인터럽트 중 23번 인터럽트 "3f00b880.mailbox" 인터럽트에 대해 살펴볼게요.
         CPU0       CPU1       CPU2       CPU3        
23:     1264          0          0          0  ARMCTRL-level   1 Edge      3f00b880.mailbox 

우선 23은 인터럽트 번호이고 CPU0부터 CPU3은 CPU 별로 인터럽트가 발생한 횟수를 보여줍니다. 위의 경우 CPU0에 1264번 인터럽트가 발생했다고 말해주는군요.

Edge는 이 인터럽트를 식별하는 방식을 나타냅니다. 인터럽트 신호가 High<->Low로 떨어질 때 인터럽트가 발생했다고 보는 것이지요. 마지막으로 "3f00b880.mailbox"은 인터럽트 이름입니다.

그럼 위와 같은 정보를 출력하는 함수는 어디일까요? 정답은 show_interrupts 함수입니다. 그럼 show_interrupts 함수에서 어떻게 위와 같은 정보를 출력하는지 예외 처리 코드를 제외하고 핵심 코드만 살펴볼까요?
[kernel/irq/proc.c]
1 int show_interrupts(struct seq_file *p, void *v)
2 {
3  static int prec;
4
5 unsigned long flags, any_count = 0;
6 int i = *(loff_t *) v, j;
7 struct irqaction *action;
8 struct irq_desc *desc;
//..
9 irq_lock_sparse();
10 desc = irq_to_desc(i);
//..
11 seq_printf(p, "%*d: ", prec, i);
12 for_each_online_cpu(j)
13 seq_printf(p, "%10u ", kstat_irqs_cpu(i, j));
14
//...
15 #ifdef CONFIG_GENERIC_IRQ_SHOW_LEVEL
16 seq_printf(p, " %-8s", irqd_is_level_type(&desc->irq_data) ? "Level" : "Edge");
17 #endif
18 if (desc->name)
19 seq_printf(p, "-%-8s", desc->name);
20
21 if (action) {
22 seq_printf(p, "  %s", action->name);
23 while ((action = action->next) != NULL)
24 seq_printf(p, ", %s", action->name);
25 }

다음 코드는 인터럽트 번호인 i 인자를 받아 인터럽트 디스크립터를 받습니다. irq_to_desc 함수는 인터럽트 번호로 해당 인터럽트 디스크립터를 알아낼 수 있으니 참 유용한 일을 하네요.
10 desc = irq_to_desc(i);
 
11번째 줄 코드에서는 인터럽트 번호를 출력하고 12번째와 13번째 코드로 각 CPU별로 발생한 인터럽트 횟수를 출력합니다. 
11 seq_printf(p, "%*d: ", prec, i);
12 for_each_online_cpu(j)
13 seq_printf(p, "%10u ", kstat_irqs_cpu(i, j));

16번째 코드는 인터럽트를 식별 방법을 확인해서 출력합니다.
16 seq_printf(p, " %-8s", irqd_is_level_type(&desc->irq_data) ? "Level" : "Edge");
 
다음은 인터럽트 이름을 출력하는 코드입니다. 
23번째부터 25번째 줄 코드는 하나의 인터럽트를 여러 이름으로 등록할 수 있는데 이 정보를 확인하기 위한 코드입니다.
21 if (action) {
22 seq_printf(p, "  %s", action->name);
23 while ((action = action->next) != NULL)
24 seq_printf(p, ", %s", action->name);
25 }

/proc/interrupts 파일에서 인터럽트 정보를 확인했습니다. 여기서 한 가지 기억해야 할 점이 있는데요. 우리가 보는 커널 메시지나 디버깅 정보는 리눅스 커널 코드에서 출력해주는 것입니다. 따라서 해당 로그가 메시지를 리눅스 커널의 어떤 코드가 실행하면서 출력하는지 살펴보면 더 많은 것을 얻을 수 있습니다.
태그 : , , , , ,
트랙백(0)핑백(12)덧글(0)

[라즈베리파이] 인터럽트 디버깅 - 인터럽트 핸들러 파악 #CS [라즈베리파이][커널]인터럽트


우리는 다음 __handle_irq_event_percpu 함수 13번째 코드에서 인터럽트 핸들러가 호출된다고 배웠습니다. 
1 irqreturn_t __handle_irq_event_percpu(struct irq_desc *desc, unsigned int *flags)
2 {
3 irqreturn_t retval = IRQ_NONE;
4 unsigned int irq = desc->irq_data.irq;
5 struct irqaction *action;
6
7 record_irq_time(desc);
8
9 for_each_action_of_desc(desc, action) {
10 irqreturn_t res;
11
12 trace_irq_handler_entry(irq, action);
13 res = action->handler(irq, action->dev_id); // <<--
14 trace_irq_handler_exit(irq, action, res);

그리고 ftrace 로 인터럽트 이벤트를 켜서 각종 인터럽트가 얼마나 자주 인터럽트가 호출되는지 알게 되었죠. 그럼 인터럽트별로 인터럽트 핸들러 함수가 뭔지 파악하려면 어떻게 해야 할까요? 

여기까지 배운 정보를 바탕으로 다음 패치 코드를 작성하면 인터럽트 핸들러 정보를 파악할 수 있습니다.
diff --git a/kernel/irq/handle.c b/kernel/irq/handle.c
index 79f987b94..2c2ec3f63 100644
--- a/kernel/irq/handle.c
+++ b/kernel/irq/handle.c
@@ -142,8 +142,13 @@ irqreturn_t __handle_irq_event_percpu(struct irq_desc *desc, unsigned int *flags
1 
2 for_each_action_of_desc(desc, action) {
3  irqreturn_t res;
4+     void *irq_handler = (void*)action->handler;
5 
6      trace_irq_handler_entry(irq, action);
7+
8+ trace_printk("[+] irq:[%d] handler: %pS caller:(%pS) \n", 
9+ irq, irq_handler, (void *)__builtin_return_address(0));
10  res = action->handler(irq, action->dev_id);
11  trace_irq_handler_exit(irq, action, res);
 
위 코드를 빌드한 후 라즈베리안에 설치한 다음에 5.7.2 ftrace 인터럽트 이벤트 절에 소개한 [irq_ftrace.sh] 스크립트를 실행하면 다음 ftrace 로그를 확인할 수 있습니다.
1 kworker/0:1-29    [000] d.h.    89.431707: irq_handler_entry: irq=23 name=3f00b880.mailbox
2 kworker/0:1-29    [000] d.h.    89.431712: __handle_irq_event_percpu: [+] irq:[23] irq_handler: bcm2835_mbox_irq+0x0/0x60 caller:(handle_irq_event_percpu+0x2c/0x68) 
3 kworker/0:1-29    [000] d.h.    89.431719: irq_handler_exit: irq=23 ret=handled
4 <idle>-0     [000] d.h.    89.432021: irq_handler_entry: irq=62 name=dwc_otg
5 <idle>-0     [000] d.h.    89.432025: __handle_irq_event_percpu: [+] irq:[62] irq_handler: dwc_otg_common_irq+0x0/0x28 caller:(handle_irq_event_percpu+0x2c/0x68)
6 <idle>-0     [000] d.h.    89.432028: irq_handler_exit: irq=62 ret=unhandled

위 로그에서 23번 인터럽트에 대한 정보를 상세히 분석해볼까요? 우선 pid가 29번인 kworker/0:1-29 프로세스 실행 도중 irq=23번 인터럽트가 발생했다는 사실을 알 수 있습니다.
1 kworker/0:1-29    [000] d.h.    89.431707: irq_handler_entry: irq=23 name=3f00b880.mailbox
2 kworker/0:1-29    [000] d.h.    89.431712: __handle_irq_event_percpu: [+] irq:[23]irq_handler: bcm2835_mbox_irq+0x0/0x60 caller:(handle_irq_event_percpu+0x2c/0x68) 
 
이번에는 두 번째 줄 로그를 분석할 차례입니다. 
이 ftrace 로그를 출력하는 함수는 __handle_irq_event_percpu이고 이 함수를 호출한 함수는 handle_irq_event_percpu라는 기본 정보와 irq23의 인터럽트 핸들러는 bcm2835_mbox_irq라는 정보를 알 수 있습니다.

이번에는 62번 인터럽트에 대한 로그를 짚어 보겠습니다.
4 <idle>-0     [000] d.h.    89.432021: irq_handler_entry: irq=62 name=dwc_otg
5 <idle>-0     [000] d.h.    89.432025: __handle_irq_event_percpu: [+] irq:[62] irq_handler: dwc_otg_common_irq+0x0/0x28 caller:(handle_irq_event_percpu+0x2c/0x68)
6 <idle>-0     [000] d.h.    89.432028: irq_handler_exit: irq=62 ret=unhandled

pid가 0인 idle 프로세스가 실행 도중 62번 dwc_otg 인터럽트가 발생했고 이 인터럽트 핸들러는 dwc_otg_common_irq란 정보를 알 수 있죠.
태그 : , , , , , , , ,
트랙백(0)핑백(12)덧글(0)

[라즈베리파이] 인터럽트 디버깅 - ftrace 인터럽트 이벤트 #CS [라즈베리파이][커널]인터럽트


라즈베리안 리눅스 커널은 아래 ftrace 로그를 볼 수 있는 컨피그가 기본 설정돼 있습니다. 그래서 ftrace만 설정하면 됩니다. 그럼ftrace로 인터럽트 동작을 어떻게 확인할 수 있을까요? ftrace event 중에 인터럽트가 있으니 다음 명령어로 해당 event를 키면 됩니다. 
echo 1 > /sys/kernel/debug/tracing/events/irq/irq_handler_entry/enable
echo 1 > /sys/kernel/debug/tracing/events/irq/irq_handler_exit/enable

다음과 같은 코드를 작성하고 irq_ftrace.sh란 스크립트로 저장한 후 이 스크립트를 실행하면 ftrace로 인터럽트를 로그를 볼 수 있습니다. 
[irq_ftrace.sh]
#!/bin/sh

echo 0 > /sys/kernel/debug/tracing/tracing_on
sleep 1
echo "tracing_off"

echo nop > /sys/kernel/debug/tracing/current_tracer
echo 0 > /sys/kernel/debug/tracing/events/enable
sleep 1

echo 1 > /sys/kernel/debug/tracing/events/sched/sched_switch/enable
sleep 1

echo 1 > /sys/kernel/debug/tracing/events/irq/irq_handler_entry/enable
echo 1 > /sys/kernel/debug/tracing/events/irq/irq_handler_exit/enable

echo 1 > /sys/kernel/debug/tracing/tracing_on
echo "tracing_on"
 
참고로, ftrace 을 설정하기 위해서 여러 커맨드를 입력해야 하는데 이 명령어들을 하나의 셸 스크립트로 모으면 효율적으로 ftrace를 설정할 수 있습니다. 아래에서 sched_switch 이벤트를 추가한 이유는 어떤 프로세스에서 인터럽트를 처리하는지 확인할 수 있기 때문입니다.

이렇게 설정한 후 5초 후 “tail -400 /sys/kernel/debug/tracing/trace” 명령어로 ftrace log을 열어보면 다음 정보를 볼 수 있습니다.

<idle>-0     [000] d.h. 4486.576254: irq_handler_entry: irq=62 name=dwc_otg_hcd:usb1

<idle>-0     [000] d.h. 4486.576258: irq_handler_exit: irq=62 ret=handled

<idle>-0     [000] d.h. 4486.577287: irq_handler_entry: irq=17 name=arch_timer

<idle>-0     [000] d.h. 4486.577294: irq_handler_exit: irq=17 ret=handled

<idle>-0     [000] d... 4486.577315: sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120prev_state=R ==>

    next_comm=kworker/0:2 next_pid=20114 next_prio=120

kworker/0:2-20114[000] d.h.  4486.577335:irq_handler_entry: irq=17 name=arch_timer

kworker/0:2-20114[000] d.h.  4486.577340:irq_handler_exit: irq=17 ret=handled

kworker/0:2-20114[000] d.h.  4486.577344:irq_handler_entry: irq=23 name=3f00b880.mailbox

kworker/0:2-20114[000] d.h.  4486.577346:irq_handler_exit: irq=23 ret=handled

kworker/0:2-20114[000] d...  4486.577377: sched_switch:prev_comm=kworker/0:2 prev_pid=20114 prev_prio=120 prev_state=D ==>

    next_comm=swapper/0next_pid=0next_prio=120

<idle>-0     [000] d.h. 4486.577380: irq_handler_entry: irq=17 name=arch_timer

<idle>-0     [000] dnh. 4486.577385: irq_handler_exit: irq=17 ret=handled

<idle>-0     [000] d... 4486.577387: sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120prev_state=R ==>

        next_comm=kworker/0:2 next_pid=20114next_prio=120

kworker/0:2-20114[000] d...  4486.577391: sched_switch:prev_comm=kworker/0:2 prev_pid=20114 prev_prio=120 prev_state=D ==>

        next_comm=swapper/0 next_pid=0next_prio=120

<idle>-0     [000] d.h. 4486.578509: irq_handler_entry: irq=23 name=3f00b880.mailbox

<idle>-0     [000] dnh. 4486.578517: irq_handler_exit: irq=23 ret=handled

<idle>-0     [000] d... 4486.578528: sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120prev_state=R ==>

     next_comm=kworker/0:2 next_pid=20114next_prio=120

kworker/0:2-20114[000] d...  4486.578549: sched_switch:prev_comm=kworker/0:2 prev_pid=20114 prev_prio=120 prev_state=t ==>

            next_comm=swapper/0 next_pid=0next_prio=120


그럼 이제 ftrace log에서 아래 로그가 어떤 의미인지 차근차근 분석해볼까요?
kworker/0:2-20114 [000] d.h.  4486.577344: irq_handler_entry: irq=23 name=3f00b880.mailbox
kworker/0:2-20114 [000] d.h.  4486.577346: irq_handler_exit: irq=23 ret=handled
 
아래 로그에서 볼드체로 된 부분은 눈여겨보시면 kworker/0:2-20114는 pid가 20114인 kworker/0:2란 이름의 프로세스란 의미입니다. 프로세스 이름이 kworker/0:2이니 워커 쓰레드이네요. 
kworker/0:2-20114 [000] d.h.  4486.577344: irq_handler_entry: irq=23 name=3f00b880.mailbox
kworker/0:2-20114 [000] d.h.  4486.577346: irq_handler_exit: irq=23 ret=handled

[000]은 해당 프로세스가 돌고 있는 CPU 번호입니다. 0번 CPU에서 돌고 있었네요. 그 다음에 보이는 4486.577344는 초 단위 타임스탬프로 시간을 나타내죠.
kworker/0:2-20114 [000] d.h.  4486.577344: irq_handler_entry: irq=23 name=3f00b880.mailbox
kworker/0:2-20114 [000] d.h.  4486.577346: irq_handler_exit: irq=23 ret=handled
 
irq_handler_entry는 인터럽트 핸들러가 실행 직전을 의미하고, irq_handler_exit는 인터럽트 핸들러가 종료됐다는 것을 의미합니다. 
kworker/0:2-20114 [000] d.h.  4486.577344: irq_handler_entry: irq=23 name=3f00b880.mailbox
kworker/0:2-20114 [000] d.h.  4486.577346: irq_handler_exit: irq=23 ret=handled
 
위 타임스탬프 정보와 함께 이 ftrace log을 해석하면 4486.577344초에 인터럽트 핸들러가 실행했고 4486.577346초에 핸들러가 종료됐네요. 이 정보로 0.002 밀리 초 동안 인터럽트 핸들러가 실행했음을 알 수 있네요. 
0.000002 = 4486.577346 - 4486.577344
 
다음은 인터럽트 번호입니다. 23번 인터럽트이네요.
kworker/0:2-20114 [000] d.h.  4486.577344: irq_handler_entry: irq=23 name=3f00b880.mailbox
kworker/0:2-20114 [000] d.h.  4486.577346: irq_handler_exit: irq=23 ret=handled

name=3f00b880.mailbox 로그는 인터럽트 이름을 알려줍니다.
kworker/0:2-20114 [000] d.h.  4486.577344: irq_handler_entry: irq=23 name=3f00b880.mailbox
kworker/0:2-20114 [000] d.h.  4486.577346: irq_handler_exit: irq=23 ret=handled
 
3f00b880.mailbox 인터럽트 핸들러는 bcm2835_mbox_probe 함수에서 다음 코드에서 초기화됩니다. dev_name(dev) 인자로 "3f00b880.mailbox" 인터럽트 이름을 지정하고 있군요.
static int bcm2835_mbox_probe(struct platform_device *pdev)
{
//...
ret = devm_request_irq(dev, platform_get_irq(pdev, 0),
       bcm2835_mbox_irq, 0, dev_name(dev), mbox);

여기서 devm_request_irq란 낯선 함수가 등장했네요.

그동안 인터럽트 설정은 request_irq 함수로만 설정하는 것으로 알고 있는데요. 디바이스 드라이버에서 devm_request_irq 함수를 써서 인터럽트를 설정하면 irq란 리소스를 struct device 구조체 내에서 체계적으로 관리할 수 있습니다. 이 점만 빼고 request_threaded_irq 함수로 인터럽트 핸들러를 초기화하는 동작은 같습니다.

이제 다음 인터럽트 발생하는 ftrace 로그를 리눅스 커널의 어느 코드에서 실행하는지 궁금하지는 않나요?
kworker/0:2-20114 [000] d.h.4486.577344: irq_handler_entry: irq=23 name=3f00b880.mailbox
kworker/0:2-20114 [000] d.h.  4486.577346: irq_handler_exit: irq=23 ret=handled
 
우리는 다음 __handle_irq_event_percpu 함수 7번째 줄 코드에서 인터럽트 핸들러를 호출한다고 배웠습니다. 이 코드 전후로 trace_irq_handler_entry, trace_irq_handler_exit 코드가 보이죠?
1 irqreturn_t __handle_irq_event_percpu(struct irq_desc *desc, unsigned int *flags)
2 {
//…
3 for_each_action_of_desc(desc, action) {
4 irqreturn_t res;
5
6 trace_irq_handler_entry(irq, action);
7 res = action->handler(irq, action->dev_id); 
8 trace_irq_handler_exit(irq, action, res);

trace_irq_handler_entry 함수는 아래 첫 번째 ftrace 로그를 출력하고 trace_irq_handler_exit 함수는 그다음 ftrace 로그를 출력합니다. 
1 kworker/0:2-20114 [000] d.h.4486.577344: irq_handler_entry: irq=23 name=3f00b880.mailbox
2 kworker/0:2-20114 [000] d.h.  4486.577346: irq_handler_exit: irq=23 ret=handled

이렇게 ftrace 로그로 인터럽트 이벤트를 키고 인터럽트를 분석하면 어떤 인터럽트가 얼마나 자주 호출하는지 상세히 알 수 있습니다. ftrace 로그를 열어 보면 아시겠지만 1초 동안 보통 수 백 개의 인터럽트가 발생하고 있음을 알 수 있습니다. 그러니 당연히 인터럽트 핸들러는 짧고 굵게 빨리 실행해야겠죠?

ftrace 로그로 인터럽트 정보를 확인했는데 한 가지 부족한 정보가 있습니다. 그것은 인터럽트 핸들러입니다. 다음 시간에 각 인터럽트가 발생했을 때 인터럽트 핸들러가 무엇인지 알아보겠습니다.

태그 : , , , , ,
트랙백(0)핑백(12)덧글(0)

[Trace32] 폰트 색상 변경 - setup.color [Debugging] Tips

config.t32 파일에 다음 명령어를 입력하면 Trace32 폰트 색상이 바뀝니다.
PALETTE 0 = 56 56 56
PALETTE 1 = 221 221 221
PALETTE 4 = 128 0 255
PALETTE 11 = 255 0 0
PALETTE 18 = 255 128 64
PALETTE 27 = 255 128 64
PALETTE 48 = 128 128 0
PALETTE 50 = 255 128 64.

Trace32를 열고 setup.color을 입력해서 폰트나 텍스트 상자 색상을 바꿀 수도 있습니다.
태그 : , ,
트랙백(0)덧글(0)

[라즈베리파이] 인터럽트 핸들러 등록(2) - #CS [라즈베리파이][커널]인터럽트


이번에는 다른 코드를 입력해서 인터럽트 핸들러와 인터럽트 디스크립터에 대해 알아볼게요.

다음 패치는 인터럽트 핸들러를 등록한 후 바로 해당 인터럽트 번호로 인터럽트 디스크립터를 커널 함수로 읽어와 인터럽트 설정 정보를 출력합니다. 제대로 인터럽트 핸들러를 등록했는지 점검하고 싶을 때 활용하면 좋은 코드입니다. 파라미터가 인터럽트 번호이므로 인터럽트 번호만 대입하면 다른 함수에서도 호출할 수 있죠.

이제부터 코드를 어떻게 작성했는지 함께 살펴볼까요? 우선 dwc_otg_driver_probe 함수 위에 다음 코드를 입력합니다.
1 static void interrupt_debug_irq_desc(int irq_num)
2 {
3 struct irqaction *action;
4 struct irq_desc *desc;
5
6 desc = irq_to_desc(irq_num);
7
8 if (!desc ) {
9 pr_err("invalid desc at %s line: %d\n", __func__, __LINE__);
10 return;
11 }
12
13 action = desc->action;
14
15 if (!action ) {
16 pr_err("invalid action at %s line:%d \n", __func__, __LINE__);
17 return;
18 }
19
20 printk("[+] irq_desc debug start \n");
21
22 printk("irq num: %d name: %8s \n", action->irq , action->name);
23 printk("dev_id:0x%x \n", (unsigned int)action->dev_id);
24
25      if (action->handler) {
26 printk("interrupt handler: %pF \n", action->handler);
27 }
28
29 printk("[-] irq_desc debug end \n");
30}
 
/**
 * This function is called when an lm_device is bound to a
 * dwc_otg_driver. It creates the driver components required to
 * control the device (CIL, HCD, and PCD) and it initializes the
 * device. The driver components are stored in a dwc_otg_device
 * structure. A reference to the dwc_otg_device is saved in the
 * lm_device. This allows the driver to access the dwc_otg_device
 * structure on subsequent calls to driver methods for this device.
 *
 * @param _dev Bus device
 */
static int dwc_otg_driver_probe(
#ifdef LM_INTERFACE
       struct lm_device *_dev

이제 패치 코드를 조금 더 분석해볼까요?

우선 여섯 번째 줄 코드부터 볼게요. irq_to_desc 란 함수를 써서 세부 인터럽트 정보가 있는 인터럽트 디스크립터를 읽어옵니다. 
6 desc = irq_to_desc(irq_num);
 
여기서 인터럽트 디스크립터 구조체는 struct irq_desc 이니 눈여겨보세요. 조금 난해한 함수로 보이지만 함수 이름처럼 인터럽트 번호를 받아 인터럽트 디스크립터를 알려줍니다.

이번에는 13번째 줄 코드입니다.
13 action = desc->action;

인터럽트 디스크립터에서 struct irq_desc.action란 멤버가 인터럽트 핸들러, 인터럽트 번호, 인터럽트 플레그 정보를 담고 있습니다. 이 정보를 출력하려고 desc->action 이란 포인터를 struct irqaction 구조체인 action이란 지역 변수로 읽어 옵니다.

22번째부터 25번째까지 코드를 볼 차례입니다. 인터럽트에서 가장 중요한 정보를 출력하는 코드이니 조금 더 집중해서 볼 필요가 있습니다. 
22 printk("irq num: %d name: %8s \n", action->irq , action->name);
23 printk("dev_id:0x%x \n", (unsigned int)action->dev_id);
24
25      if (action->handler) {
26 printk("interrupt handler: %pF \n", action->handler);
27 }
 
인터럽트 이름, 인터럽트 번호, 디바이스 핸들 정보인 action->dev_id 그리고 인터럽트 핸들러를 출력합니다. 참고로 printk로 함수 포인터를 심볼 정보로 보고 싶을 때는 %pF로 옵션을 주면 됩니다.

이번에는 interrupt_debug_irq_desc 함수를 호출할 함수를 살펴볼게요. 이전에dwc_otg_driver_probe 함수에서 dwc_otg_common_irq 인터럽트 핸들러를 등록할 때 request_irq 함수를 호출했었죠? 이 코드 다음에 이 함수를 호출하면 됩니다.
static int dwc_otg_driver_probe(
#ifdef LM_INTERFACE
       struct lm_device *_dev
#elif defined(PCI_INTERFACE)
       struct pci_dev *_dev,
       const struct pci_device_id *id
#elif  defined(PLATFORM_INTERFACE)
                                       struct platform_device *_dev
#endif
    )
{
int retval = 0;
dwc_otg_device_t *dwc_otg_device;
//...
DWC_DEBUGPL(DBG_CIL, "registering (common) handler for irq%d\n",
    devirq);
dev_dbg(&_dev->dev, "Calling request_irq(%d)\n", devirq);
retval = request_irq(devirq, dwc_otg_common_irq,
                             IRQF_SHARED,
                             "dwc_otg", dwc_otg_device);
        interrupt_debug_irq_desc(devirq);

interrupt_debug_irq_desc 함수를 호출할 때 전달하는 devirq 지역 변수는 인터럽트 번호를 담고 있습니다.

위 디버깅 코드를 입력하고 라즈베이란을 구동시키면 다음과 같은 커널 로그를 확인할 수 있습니다.
[0.496039] [+] irq_desc debug start 
[0.496048] irq num: 62 name:  dwc_otg 
[0.496055] dev_id:0xb9355c40 
[0.496065] interrupt handler: dwc_otg_common_irq+0x0/0x28 
[0.496071] [-] irq_desc debug end

다음 코드에서 인터럽트 이름은 dwc_otg, 62번 인터럽트 번호로 인터럽트를 등록한다는 정보를 알 수 있죠. 
retval = request_irq(devirq, dwc_otg_common_irq,
                             IRQF_SHARED,
                             "dwc_otg", dwc_otg_device);

이렇게 우리가 알고 싶은 함수에 적절한 디버깅 코드를 입력하면 해당 코드가 어느 시점에 호출하는지 알 수 있습니다. 리눅스 커널을 익힐 때 코드만 보는 것보다 이렇게 로그를 추가해서 시스템을 돌려보면 더 많은 정보를 얻을 수 있습니다.

태그 : , , , , , ,
트랙백(0)핑백(12)덧글(0)

[Linux][ARM] Coprocessor(코프로세서) Assembly [Linux][ARM] Core Analysis

ARM 프로세스 내 Coprocessor라는 하드웨어가 있습니다. Co-Processor라는 것은 Co-worker랍니다. CPU 혼자 모든 일을 다 할 수 없으니 Co-Processor가 필요한 것입니다.

Co-Processor는 C언어 같이 어떤 코드 흐름을 제어하는 일보다는 ARM Core나 Cache을 콘트롤하는 역할을 수행합니다. 그래서 ARM 프로세스로 칩을 디자인하는 개발자는 Co-Processor를 제어하는 명령어를 달달 외우고 있죠.

Co-Processor가 있으니 당연히 Co-Processor하고 대화를 해야 겠죠. Co-Processor에게 말을 거는 방법을 역시 레지스터를 이용해서 주어진 명령어를 실행시키면 됩니다.
Co-Processor에게 말을 걸면 Co-Processor가 알아듯는 용도의 레지스터가 따로 있거든요. 

그럼 Co-Processor와 통신하는 어셈블리 명령어를 조금 더 알아볼까요? 이 패턴도 어셈블리랑 비슷하니 너무 겁 먹지 마세요.

우선 Co-Processor에게 Data를 전달하는 명령어는 3가지로 분류됩니다.
1. Co-Processor 내부 레지스터를 직접 업데이트
2. Co-Processor 내부 레지스터를 ARM 레지스터로 읽거나 반대로 업데이트
3. Co-Processor 내부 레지스터를 직접 메모리에 읽거나 반대로 메모리에 있는 값을 Co-Processor 내부 레지스터에 업데이트

Co-Processor Data 명령어를 조금 더 자세히 들여다 볼까요?

1) Co-Processor 내부 레지스터를 직접 업데이트
Co-Processor 내부 Register ↔ Co-Processor 내부 Register

여기에 붙은 모든 규칙은 Coprocessor 내부에 정의되어 있고 형식은 다음과 같습니다.
CDP Coprocessor번호, Coprocessor 명령어, CRd, CRn

Co-Processor 명령어는 Co-Processor마다 준비된 명령어가 다르니 개별적으로 만든 것입니다. 그리고 CRd는 Co-Processor 내부에 있는 레지스터로 Destination 레지스터로 사용되는 레지스터이고, CRn은 Co-Processor 내부에 있는 레지스터로 인자 레지스터입니다.

2) Co-Processor 내부 레지스터를 ARM 레지스터로 읽거나 반대로 업데이트
Coprocessor 내부 레지스터 ↔ ARM 레지스터

Co-Processor 명령은 ARM core와 Co-Processor와 통신에 쓰이며 PSR명령과 유사한 형식입니다. 
Co-Processor의 레지스터들과 직접 레지스터 값을 교환하는 명령어는 MRC, MCR 인데 M X ← Y 형식입니다.
아래 형식을 기억하면 대략 레지스터를 전달하는 흐름을 알 수 있으니 잊지 마세요.
M X ← Y 형식

여기서 R은 ARM Core의 일반 레지스터이고요, C는 Co-Processor의 레지스터를 의미합니다. 
그러니까, 각각 Co-Processor를 제어하는 명령어는 두개 인데요. 각각 레지스터를 저장하는 흐름은 다음과 같습니다.
MRC는 R←C로서 R:=Coprocessor 
MCR은 C←R로서, C:=Register

2.1 [MRC Co-Processor 번호, 무조건 0, 레지스터 번호, Co-Processor 레지스터번호, c0, 무조건 0] 포멧 

그럼 다음 명령을 실행하면 Co-Processor 15번 1번 레지스터를 r3에 전송하라는 의미입니다.
MRC p15,0x0,r3,c1,c0,0x0   ; p15,0,r3,c1,c0,0 (system control)

2.2 [MCR Co-Processor 번호, 무조건 0, 레지스터 번호, Co-Processor 레지스터번호, c0, 무조건 0] 포멧 

다음 명령을 실행하면 Co-Processor 15번 2번 레지스터에 r4 값을 전송하라는 의미입니다.
MCR p15, 0, r4, c2, c0, 0
 
이번에는 Co-Processor 15번 1번 레지스터에 r5 값을 전송하라는 명령어입니다.
MCR p15,0x0,r5,c1,c0,0x0 

3)  Co-Processor 내부 레지스터를 직접 메모리에 읽거나 반대로 메모리에 있는 값을 Co-Processor 내부 레지스터에 업데이트
Coprocessor 내부 Register ↔ Memory

마지막으로, Co-Processor 내부 레지스터와 메모리 사이에 Load, Store할 수 있는 명령이 있는데 바로 LDC, STC입니다. LDC, STC에도 preindex, postindex 방식이 엄연히 존재합니다. 하나 예제를 들면 LDC p15, c2, [r0, 0x100] 이면, Co-Processor 15번의 레지스터 2번에 r0+0x100이 가리키는 곳의 값을 load하라는 의미입니다. 일반 load와 틀림없이 같지만 앞에 Co-Processor 번호인 p15가 붙는다는 것만 다릅니다. LDR은 Register의 R, LDC는 Co-Processor의 C인 것이죠. 

Co-Processor 15는 MMU, Cache에 관련된 Co-Processor로서, 이 레지스터를 잘 콘트롤 해야 일이 아주 많습니다.
태그 : , , , , ,
트랙백(0)덧글(0)

[라즈베리파이] 인터럽트 핸들러 등록(1) - #CS [라즈베리파이][커널]인터럽트


인터럽트 핸들러를 등록하는 처리 과정을 배우기 전에 우선 핸들러란 단어의 의미를 알 필요가 있습니다. 보통 핸들러는 동적으로 바뀌는 액션을 처리하기 위한 용도로 호출합니다. 그래서 핸들러는 함수 포인터로 등록해서 처리하는 경우가 대부분입니다. 만약 어떤 시스템에 인터럽트를 36개로 설계했으면 36개의 if else 문으로 인터럽트 핸들러를 호출하면 어떻게 될까요? 만약 다른 시스템에서 40개면요? 참 리눅스 커널 코드를 유지 보수하기 어렵겠죠. 그래서 인터럽트 핸들러는 함수 포인터로 등록합니다. 인터럽트 핸들러는 해당 인터럽트를 처리하기 위한 함수들이며 보통 인터럽트 종류만큼 인터럽트 핸들러 함수들이 있습니다.

인터럽트 핸들러 등록 시 기본 파라미터
해당 인터럽트가 발생하면 해당 인터럽트 핸들러 함수가 호출돼야 합니다. 이를 위해 디바이스 드라이버 코드에서 request_irq 함수을 써서 인터럽트 핸들러를 등록해야 합니다. 그럼request_irq 함수를 실제 어떻게 사용하는지 라즈베리안 리눅스 커널 코드를 잠깐 살펴보겠습니다. 

[drivers/usb/host/dwc_otg/dwc_otg_driver.c] 파일에 있는 dwc_otg_driver_probe 함수를 열어 볼까요? dwc_otg_driver_probe 함수를 보면 dwc_otg_common_irq 함수를 인터럽트 핸들러로 등록합니다.
[drivers/usb/host/dwc_otg/dwc_otg_driver.c]
static int dwc_otg_driver_probe()
          int retval = 0;
 dwc_otg_device_t *dwc_otg_device;
          int devirq;
//...
dev_dbg(&_dev->dev, "Calling request_irq(%d)\n", devirq);
retval = request_irq(devirq, dwc_otg_common_irq,
                             IRQF_SHARED,
                             "dwc_otg", dwc_otg_device);

각 파라미터는 다음과 같이 대응합니다.
- 인터럽트 번호: devirq
- 인터럽트 핸들러: dwc_otg_common_irq
- 인터럽트 이름: " dwc_otg "
- dev_info: struct dwc_otg_device_t 타입의 디바이스 처리 인스턴스
- flags: 0x80(IRQF_SHARED)
 
request_irq 함수 마지막 파라미터는 dwc_otg_device_t 구조체인 dwc_otg_device란 포인터 변수인데, 이 주소는 인터럽트 핸들러에서 쓰는 핸들로 등록합니다. 이 포인터는 인터럽트 디스크립터의 struct irq_desc->action.dev_info 멤버로 저장됩니다. 이후 나중에 인터럽트 핸들러인 dwc_otg_common_irq 함수가 호출될 때 파라미터로 그대로 전달받습니다.

그럼 이제 위 코드에서 설정한 인자를 request_irq 함수가 어떻게 처리하는지 살펴볼 차례입니다.
request_irq(unsigned int irq, irq_handler_t handler, unsigned long flags,
    const char *name, void *dev)
{
return request_threaded_irq(irq, handler, NULL, flags, name, dev);
}

코드를 보니 디바이스 드라이버에서 request_irq 함수를 호출하지만 파라미터를 그대로 실어서 request_threaded_irq함수를 호출한다는 사실을 알 수 있습니다. request_threaded_irq 함수를 살펴보면 인터럽트 디스크립터 구조체 struct irq_desc로 메모리를 할당하고 디바이스 드라이버에서 채워준 파라미터를 아래 코드에서 설정합니다.
int request_threaded_irq(unsigned int irq, irq_handler_t handler,
 irq_handler_t thread_fn, unsigned long irqflags,
 const char *devname, void *dev_id)
{
struct irqaction *action;
struct irq_desc *desc;
int retval;
// ..생략..
action->handler = handler;
action->thread_fn = thread_fn;
action->flags = irqflags;
action->name = devname;
action->dev_id = dev_id;
 
해당 인터럽트가 떠서 dwc_otg_common_irq 인터럽트 핸들러가 호출되면, void 타입 dev_id 포인터는 struct dwc_otg_device_t 구조체로 캐스팅됩니다. 이제irq 62번에 해당하는 dwc_otg_common_irq 핸들러 함수를 열어서 정말 이렇게 동작하는지 살펴볼까요?
1 static irqreturn_t dwc_otg_common_irq(int irq, void *dev)
2 {
3 int32_t retval = IRQ_NONE;
4
5 retval = dwc_otg_handle_common_intr(dev);
6 if (retval != 0) {
7 S3C2410X_CLEAR_EINTPEND();
8 }
9 return IRQ_RETVAL(retval);
10 }
11 int32_t dwc_otg_handle_common_intr(void *dev)
12 {
13 int retval = 0;
14 gintsts_data_t gintsts;
15 gintmsk_data_t gintmsk_reenable = { .d32 = 0 };
16 gpwrdn_data_t gpwrdn = {.d32 = 0 };
17 dwc_otg_device_t *otg_dev = dev;

위 함수에서 다섯 번째 줄 코드를 보면 dwc_otg_common_irq함수 인자인 dev 를 dwc_otg_handle_common_intr 함수에 그대로 전달합니다.
5 retval = dwc_otg_handle_common_intr(dev);
 
이후 dwc_otg_handle_common_intr 함수에서는 전달받은 dev 인자를 dwc_otg_device_t 타입 변수로 전달합니다. dwc_otg_handle_common_intr 함수를 조금 더 분석하면 이 otg_dev 자료구조로 디바이스 드라이버나 하드웨어를 제어한다는 점을 알 수 있습니다.
17 dwc_otg_device_t *otg_dev = dev;

이렇게 인터럽트를 처리하기 위한 자료구조를 포인터로 request_irq 함수 마지막 파라미터로 등록하면 인터럽트 핸들러에서 이 포틴어를 캐스팅해서 쓸 수 있습니다. 
request_irq(unsigned int irq, irq_handler_t handler, unsigned long flags,
    const char *name, void *dev)
 
이를 다른 용어로 디바이스 핸들이라고도 합니다. 이런 기법은 인터럽트 핸들러를 처리할 때 아주 많이 쓰이니 코드를 자주 보면서 눈에 익힐 필요가 있습니다.

그럼 이제까지 배운 내용이 실제 어떻게 동작하는지 알아보겠습니다. 코드를 짜서 실제 보드에서 어떤 로그가 찍히는지 확인해야 공부한 내용이 더 오래 머릿속에 남거든요.

인터럽트 핸들러 등록 동작 확인하기
우리는 request_irq 함수로 인터럽트 핸들러를 등록하면 request_threaded_irq 함수에서 인터럽트 디스크립터에 해당 인터럽트 설정 정보를 저장하는 코드를 살펴봤습니다. 이제 실제 라즈베리파이에서 어떤 코드 흐름으로 인터럽트 핸들러를 등록하는지 알아봐야 할 차례입니다. 

그럼 이 동작은 어떻게 확인할까요? request_threaded_irq 함수에 적절한 디버깅 코드를 추가하면 인터럽트 핸들러를 등록 과정을 알 수 있습니다. 그럼 라즈베리안에 다음 디버깅 코드를 입력하면서 이 정보를 확인해 볼까요?

아래 코드와 같이 request_threaded_irq 함수에서 7번째와 11번째 코드에서 인터럽트 핸들러 정보를 인터럽트 디스크립터에 저장합니다.
1 int request_threaded_irq(unsigned int irq, irq_handler_t handler,
2  irq_handler_t thread_fn, unsigned long irqflags,
3  const char *devname, void *dev_id)
4{
5 struct irqaction *action;
6 struct irq_desc *desc;
//...
7 action->handler = handler;
8 action->thread_fn = thread_fn;
9 action->flags = irqflags;
10 action->name = devname;
11 action->dev_id = dev_id;
12
13         if (irq == 62 || irq == 92 ) {
14 printk("[+][irq_debug] irq_num: %d, func: %s, line:%d, caller:%pS \n", 
15 irq, __func__, __LINE__, (void *)__builtin_return_address(0));
16 dump_stack();
17 }

이 코드 다음에 위와 같이 13번째와 17번째 코드를 입력하면 인터럽트 핸들러를 등록할 때 콜스택을 커널 로그로 볼 수 있습니다.

그럼 디버깅 코드를 조금 더 자세히 살펴볼게요. 
우선 13번째 줄 코드입니다. request_threaded_irq 함수 첫 번째 인자로 irq가 전달됩니다. 이 값은 unsigned int 타입으로 인터럽트 번호를 의미합니다.
13         if (irq == 62 || irq == 92 ) {
 
그래서 인터럽트 번호가 62번, 92번일 때만 if 문 아래에 코드가 실행합니다. 이 조건을 추가한 이유는 모든 인터럽트에 대한 커널 로그 정보를 출력하면 시스템에 과부하를 줄 수 있기 때문입니다. 

다음은 커널 로그를 출력하는 코드입니다.
14 printk("[+][irq_debug] irq_num: %d, func: %s, line:%d, caller:%pS \n", 
15 irq, __func__, __LINE__, (void *)__builtin_return_address(0));

irq는 인터럽트 번호이고 __func__, __LINE__은 각각 해당 코드의 함수 이름과 코드 라인 정보를 알려주는 매크로입니다. __builtin_return_address(0) 빌트인 매크로는 자기 자신을 호출한 함수 정보를 알려주죠. 
 
__func__, __LINE__, __builtin_return_address(0) 매크로는 리눅스 커널에 다양한 방식으로 활용되고 있으니, 처음 보는 함수를 디버깅할 때 자주 활용하면 좋습니다.

이번에는 핵심 디버깅 코드입니다. 함수 이름과 같이 현재 코드를 실행한 콜스택 정보를 출력합니다.
16 dump_stack();
 
위 코드를 입력하고 커널 빌드를 한 후 커널 이미지를 라즈베리안에 설치합니다. 이후 리부팅을 시키고 커널 로그를 열어보면 다음 로그를 확인할 수 있습니다. 참고로 라즈베리안에서 커널 로그는 /var/log/kern.log에 저장됩니다.
[0.696159] Dedicated Tx FIFOs mode
[0.696436] [+][irq_debug] irq_num: 62, func: request_threaded_irq, line:1777, caller:pcd_init+0x138/0x240 
[0.696449] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.14.39-v7+ #11
[0.696456] Hardware name: BCM2835
[0.696476] [<8010ffe0>] (unwind_backtrace) from [<8010c21c>] (show_stack+0x20/0x24)
[0.696494] [<8010c21c>] (show_stack) from [<8078721c>] (dump_stack+0xc8/0x10c)
[0.696514] [<8078721c>] (dump_stack) from [<801780f0>] (request_threaded_irq+0x1a4/0x1a8)
[0.696531] [<801780f0>] (request_threaded_irq) from [<805d38e4>] (pcd_init+0x138/0x240)
[0.696548] [<805d38e4>] (pcd_init) from [<805c5768>] (dwc_otg_driver_probe+0x728/0x884)
[0.696565] [<805c5768>] (dwc_otg_driver_probe) from [<805464f8>] (platform_drv_probe+0x60/0xc0)
[0.696583] [<805464f8>] (platform_drv_probe) from [<80544a84>] (driver_probe_device+0x244/0x2f8)
[0.696603] [<80544a84>] (driver_probe_device) from [<80544c00>] (__driver_attach+0xc8/0xcc)
[0.696621] [<80544c00>] (__driver_attach) from [<80542c0c>] (bus_for_each_dev+0x78/0xac)
[0.696640] [<80542c0c>] (bus_for_each_dev) from [<805443a0>] (driver_attach+0x2c/0x30)
[0.696659] [<805443a0>] (driver_attach) from [<80543de8>] (bus_add_driver+0x114/0x220)
[0.696678] [<80543de8>] (bus_add_driver) from [<805453a4>] (driver_register+0x88/0x104)
[0.696696][<805453a4>](driver_register) from [<80546444>](__platform_driver_register+0x50/0x58)
[0.696713][<80546444>](__platform_driver_register) from[<80b39a60>] (dwc_otg_driver_init+0x74/0x120)
[0.696733] [<80b39a60>] (dwc_otg_driver_init) from [<80101c1c>] (do_one_initcall+0x54/0x17c)
[0.696753] [<80101c1c>] (do_one_initcall) from [<80b01058>](kernel_init_freeable+0x224/0x2b8)
[0.696771] [<80b01058>] (kernel_init_freeable) from [<8079c1f0>] (kernel_init+0x18/0x124)
[0.696788] [<8079c1f0>] (kernel_init) from [<801080cc>] (ret_from_fork+0x14/0x28)
[0.696875] WARN::dwc_otg_hcd_init:1046: FIQ DMA bounce buffers: virt = 0xbad04000 dma = 0xfad04000 len=9024

위 로그는 인터럽트 62번을 설정할 때 콜스택 정보를 보여줍니다. 커널 로그에 찍히는 콜스택에 do_one_initcall/platform_drv_probe 함수가 보이니 리눅스 커널이 부팅할 때 인터럽트를 핸들러를 설정한다는 정보를 알 수 있습니다.

사실 아래 로그가 출력될 때 “[0.696436]”은 커널 부팅 후 초 단위 타임스탬프 정보를 알려줍니다. 즉 부팅 후 0.696436초에 이 코드가 실행됐다는 의미죠. .
[0.696436] [+][irq_debug] irq_num: 62, func: request_threaded_irq, line:1777, caller:pcd_init+0x138/0x240 
 
그리고 62번 인터럽트는 pcd_init 함수에서 설정하고 있다는 정보도 확인할 수 있습니다.

정리하면 인터럽트 핸들러는 커널이 부팅하는 과정에서 디바이스 드라이버를 초기화할 때 설정한다는 점을 알 수 있습니다. 코드를 분석하다가 커널 로그로 실제 해당 코드가 언제 수행되는지 알게 되니 더 많은 것을 얻을 수 있죠.

태그 : , , , , , ,
트랙백(0)핑백(12)덧글(0)

[Linux][Kernel] current 매크로 (3) [라즈베리파이][커널]매크로분석



여기까지 처리 과정을 정리하면 current_thread_info 매크로 함수에 접근해서 현재 실행 중인 프로세스의 태스크 디스크립터 정보를 포인터 형태로 얻어온다 알 수 있습니다. 그런데 current_thread_info 매크로 함수 코드 분석은 생소한 용어들이 많이 보여 이해하기가 어렵습니다. 그 이유는 이 코드가 상당히 많은 공학적 의미를 담고 있기 때문입니다. 그럼 조금 더 깊이 current 매크로를 분석 할까요?

첫 번째 코드를 함께 볼까요? 이 코드는 현재 구동 중인 프로세스의 스택 주소를 current_stack_pointer 변수로 가져오는 명령어입니다.
1 register unsigned long current_stack_pointer asm ("sp");

asm ("sp") 명령어부터 배워야 하는데요. 이 어셈블리 명령어는 현재 실행 중인 코드의 스택 주소 위치를 알려줍니다. 우리가 보는 모든 함수는 프로세스 스택 공간에서 실행된다는 점을 알고 있죠? 이 명령어와 조합해서 1번 코드와 같이 선언하면 current_stack_pointer 전역 변수에 스택 주소를 저장합니다.
(current_stack_pointer & ~((((1UL) << 12) << 1) - 1));

이번에는 위 코드에서 볼드체로 돼 있는 연산자를 해석할 차례입니다.

<< 연산자는 다음과 같이 X란 피연산자를 N만큼 왼쪽으로 비트 쉬프트 실행합니다. 피연산자인 X를 왼쪽으로 N 비트만큼 쉬프트(Left Shift) 연산을 하면 X에 2n를 곱한 결과와 같습니다.
X * 2n = X << N

그럼 1 << 12 연산을 이 규칙으로 계산하면 다음과 같이 0x1000이 됩니다.
0x1000 = 1 * 0x1000(4096) = 1 * 212 = (1UL) << 12

이제 여기까지 분석한 내용을 원래 코드에서 업데이트해볼까요? 
(current_stack_pointer & ~((((1UL) << 12) << 1) - 1));
(current_stack_pointer & ~(((0x1000) << 1) - 1));

이제는 ((0x1000) << 1) 코드를 계산해야 할 차례입니다. 이 연산자를 위에서 배운 바와 같이 X * 2n = X << N 규칙에 따라 계산해볼까요? 결과는 0x2000입니다.
0x1000 * 21 = 0x2000

여기까지 분석한 내용을 모아서 원래 코드를 표현하면 다음과 같습니다. 0x1fff값은 (0x2000 – 1) 연산의 결과입니다.
(current_stack_pointer & ~((((1UL) << 12) << 1) - 1));
(current_stack_pointer & ~(((0x1000) << 1) - 1));
(current_stack_pointer & ~((0x2000) - 1));
(current_stack_pointer & ~(0x1fff));

이제 ~란 연산자가 보이는데요. 이 연산자는 비트를 모두 역전시킵니다. 0x1fff를 이진수로 바꿔서 ~연산을 수행하면 다음과 같은 결괏값을 얻을 수 있습니다.
0001|1111|1111|1111
~연산
-------------------
1110|0000|0000|0000

1110|0000|0000|0000 이진수는 16진수로 바꾸면 0xE000이 되는 거죠. 
이제 연산자 분석의 종착역에 온 듯합니다. 현재 스택 주소에서 0xE000란 값을 AND 연산하는 코드입니다.
(current_stack_pointer & ~((((1UL) << 12) << 1) - 1));
(current_stack_pointer & ~(((0x1000) << 1) - 1));
(current_stack_pointer & ~((0x2000) - 1));
(current_stack_pointer & ~(0x1fff));
(current_stack_pointer & (0xe000));

그런데 현재 스택 주소에서 0xE000을 AND 연산하는 게 어떤 의미가 있을까요?
아래 볼드체로된 0--12비트는 모두 0이니 다른 주소와 AND 연산을 하면 0이 됩니다.
1110|0000|0000|0000(0xE000)

0xD000C248 & (0000|0000|0000) 연산을 하면 0xD000C000이 되는 거죠. 16진수 3자리 값을 모두 0으로 변환시킵니다. 
1100|0000|0000|0000|1011|0010|0100|1000 (0xD000C248)
                                 0000|0000|0000
AND ------------------------------------------
1100|0000|0000|0000|1011|0000|0000|0000 (0xD000C000)

이번에 0xE000 값에서 0xE만 빼서 이진수로 어떤 동작을 하는지 확인할 차례입니다.
이제 0xE와 AND 비트 연산을 하는 의미를 알아보려는 것이죠.
1110|0000|0000|0000

1110비트 연산을 수행하면 현재 값이 짝수면 그 값을 그대로 유지하고 홀수면 -1만큼 뺍니다.
아래 연산 결과를 참고하시면 이해가 빠를 겁니다.
0011(0x2)
1110(0xE)
--------- AND 연산
0010
0100(0x3)
1110(0xE)
--------- AND 연산
0100

이제 총정리를 할 시간입니다. 각각 스택 주소를 다음과 같다고 했을 때 0xE000 연산을 하면 아래 결과값이 되는 거죠.
스택주소 
0xD0002248 & 0xE000 = 0xD0002000
0xD0003248 & 0xE000 = 0xD0002000
0xD0004248 & 0xE000 = 0xD0004000
0xD0005248 & 0xE000 = 0xD0004000

그럼 현재 스택 주소에서 위 규칙으로 비트를 연산하는 이유는 뭘까요? ARM32 비트 아키텍처에서는 0x2000바이트 크기만큼 스택을 지정합니다. 커널이 스택 주소를 할당할 때 0x2000바이트 Align을 맞춰서 할당합니다. 즉 스택 Top 주소는 짝수 바이트란 이야기죠. 그래서 위와 같은 비트 연산으로 스택 Top 주소를 계산한 것입니다.

그러면 프로세스가 스택 공간을 어떻게 쓰는지 조금 더 자세히 알아볼까요?

스택 Top 주소 | struct thread_info {

(낮은주소)      |   unsigned longflags;

             |   int         preempt_count;

             |   mm_segment_t addr_limit;

             |   struct task_struct  *task;

             |   __u32  cpu;

             | 

             | 

             | __slab_alloc.constprop.8

             | 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

(높은주소)    |

스택Bottom주소   | ret_fast_syscall


각 프로세스는 스택 Bottom 주소부터 함수 콜을 수행하여 스택 Top 주소 방향으로 자랍니다. 담쟁이덩굴이 벽을 타고 올라가듯 말이죠. 담쟁이덩굴의 뿌리는 스택 Bottom 주소라 생각하면 조금 더 이해가 빠르겠죠. 위 그림을 보면 ret_fast_syscall 이란 함수부터 __slab_alloc.constprop.8 함수 방향으로 스택을 씁니다. 

그런데 모든 프로세스마다 스택 Top 주소에는 struct thread_info 타입의 자료 구조 데이터를 담고 있습니다. 각 프로세스마다 할당된 스택 Top 주소에 프로세스의 중요 정보를 저장하고 있는 것이죠. 이 struct thread_info 구조체 멤버 중 task가 있는데 이 멤버는 해당 프로세스의 태스크 디스크립터 주소를 가르키고 있습니다.

정리하면 current_thread_info란 매크로 인라인 함수로 스택 Top 주소를 알아낸 후 (struct thread_info)란 구조체로 캐스팅해서 task 멤버를 리턴하는 동작입니다.

어떤 함수가 실행돼도 결국 부처님 손바닥과 같이 스택 공간 내에서 돌고 있습니다. 그래서 current_thread_info란 매크로를 써서 스택 주소만 가로채면 언제든 스택 Top 주소를 통해 태스크 디스크립터를 얻어 올 수 있는 겁니다.

열 줄도 안 되는 비트 연산자 코드에 이렇게 깊은 공학적 의미가 담겨 있다니 조금 놀랍지 않나요? 커널 코드를 보다가 current 매크로를 보면 이런 원리로 태스크 디스크립터 포인터를 가져온다는 사실을 기억이 바로 떠오르겠죠. 무엇보다 어떤 함수를 보면 해당 코드는 프로세스 스택 공간 내에서 실행된다는 점도 머리에 그려 주세요.
태그 : , , ,
트랙백(0)핑백(8)덧글(0)

[Linux][Kernel] current 매크로 (2) [라즈베리파이][커널]매크로분석

이번에도 패치 코드 하나를 소개할게요. 다음 루틴은 Wait Queue 관련 함수들인데요.
diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c
index 9453efe..a1371a9 100644
--- a/kernel/sched/wait.c
2+++ b/kernel/sched/wait.c
@@ -76,6 +76,16 @@ static void __wake_up_common(wait_queue_head_t *q, unsigned int mode,
        }
 }

1 +void trace_kernel_process_name(void *param)
2 +{
3 +       char *proc_name;
4 +       struct task_struct *proc_ptr = (struct task_struct *)param;
5 +
6 +       proc_name = proc_ptr->comm;
7 +
8 +       printk("process name: %s \n", proc_name);
9 +}
10 +
 /**
  * __wake_up - wake up threads blocked on a waitqueue.
  * @q: the waitqueue
@@ -91,6 +101,7 @@ void __wake_up(wait_queue_head_t *q, unsigned int mode,
11 {
12       unsigned long flags;
13
14 +       trace_kernel_process_name(current);
15        spin_lock_irqsave(&q->lock, flags);
16       __wake_up_common(q, mode, nr_exclusive, 0, key);
17        spin_unlock_irqrestore(&q->lock, flags);

이제 차근차근 패치 코드를 살펴볼까요?
14번째 줄 코드는 current란 변수를 파라미터로 trace_kernel_process_name 함수에 전달합니다.
14 +       trace_kernel_process_name(current);
 
다음, 첫 번째부터 네 번째 코드를 살펴볼까요? 
첫 번째 코드를 보면 void 포인터 타입의 param 변수를 파라미터로 전달합니다. 
네 번째 코드에서는 param이란 파라미터를 (struct task_struct *) 형태로 캐스팅해서 proc_ptr 지역변수에 복사합니다. 

여기서 param이란 파라미터는 __wake_up 함수에서 current 변수로 전달하고 있다는 것을 눈여겨볼 필요가 있습니다. 즉 param은 현재 구동 중인 프로세스의 태스크 디스크립터 정보를 담고 있습니다.

이제 나머지 코드를 볼게요. struct task_struct구조체 멤버 중 char comm[TASK_COMM_LEN] 이 있습니다. 프로세스 이름을 char 배열 형태로 담고 있습니다. 6번째 줄 코드는 이 값을 char 타입의 proc_name 변수에 저장하고, 8번째 줄 코드에서 printk란 함수로 프로세스 이름을 커널 로그로 출력합니다.
6 +       proc_name = proc_ptr->comm;
7 +
8 +       printk("process name: %s \n", proc_name);
 
이번에도 위와 같이 코드를 수정하고 컴파일을 하면 전처리 파일이 생성되겠죠? 그럼 current란 변수가 실제 어떤 형태인지 전처리 파일을 열어서 볼까요? [kernel/sched/wait.c] 파일에 대한 전처리 파일은 [kernel/sched/.tmp_wait.i] 이란 점 참고하세요.

패치 코드에서 current 변수는 trace_kernel_process_name 이란 함수 호출 시 파라미터로 전달됐습니다. 그럼 __wake_up 함수에서 trace_kernel_process_name 함수를 호출한 코드를 봐야겠죠.
1 void __wake_up(wait_queue_head_t *q, unsigned int mode,
2    int nr_exclusive, void *key)
3 {
4  unsigned long flags;
5
6  trace_kernel_process_name((current_thread_info()->task));
7  do { do { ({ unsigned long __dummy; typeof(flags) __dummy2; (void)(&__dummy == &__dummy2); 1; }); flags = _raw_spin_lock_irqsave(spinlock_check(&q->lock)); } while (0); } while (0);
8  __wake_up_common(q, mode, nr_exclusive, 0, key);
 
6번째 줄 코드를 보니 이상한 코드가 보입니다. 분명히 current 변수로 trace_kernel_process_name 함수 파라미터를 전달했는데, (current_thread_info()->task) 코드로 변경됐습니다.

무슨 일이 일어난 건지 조금 더 짚어볼까요?
[kernel/sched/.tmp_wait.i] 전처리 파일에서 current_thread_info 코드를 검색해볼까요? 이 코드가 매크로로 선언됐을 수도 있거든요. 검색하니 다음과 같이 코드가 보입니다.
1 register unsigned long current_stack_pointer asm ("sp");
2
3 static inline __attribute__((always_inline)) __attribute__((no_instrument_function)) struct thread_info *current_thread_info(void)
4 {
5  return (struct thread_info *)
6   (current_stack_pointer & ~((((1UL) << 12) << 1) - 1));
7 }

그럼 위 코드가 어떻게 실행되는지 차례대로 살펴볼게요.
1. 첫 번째 줄 코드가 실행되면 현재 실행 중인 프로세스의 스택 주소를 읽어옵니다. 이 스택 주소를 current_stack_pointer 변수에 저장합니다. 

2.(current_stack_pointer & ~0x1fff) 비트 연산으로 현재 프로세스의 스택 Top 주소를 계산합니다. 스택 Top 주소에 (struct thread_info*)란 구조체 멤버들이 있거든요.

3.(struct thread_info*) 구조체에 task 멤버를 리턴 합니다. 
current_thread_info()->task

task란 멤버는 (struct task_struct *) 구조체인데 이는 해당 프로세스의 태스크 디스크립터입니다. 
6 +       proc_name = proc_ptr->comm;
7 +
8 +       printk("process name: %s \n", proc_name);
태그 : , , , ,
트랙백(0)핑백(8)덧글(0)

[Linux][Kernel] current 매크로 (1) [라즈베리파이][커널]매크로분석


리눅스 커널 코드를 읽다가 current란 매크로를 보신 적이 있나요? 아직 없다고요? 그럼 조금 코드를 읽다 보면 만나게 될 겁니다. 왜냐면 리눅스 커널 코드 구석구석 이 매크로를 쓰고 있거든요. 

그럼 current 매크로는 어떤 동작을 할까요? current란 매크로는 현재 구동 중인 프로세스의 태스크 디스크립터 정보를 담고 있습니다. 그럼 current 매크로가 포함된 코드를 열어 볼까요?

다음 파일 디스크립터를 할당하는 get_unused_fd_flags 함수를 잠깐 볼게요.
1 int get_unused_fd_flags(unsigned flags)
2 {
3 return __alloc_fd(current->files, 0, rlimit(RLIMIT_NOFILE), flags);
4 }
5 EXPORT_SYMBOL(get_unused_fd_flags);

여기서 잠깐 get_unused_fd_flags 함수가 어떻게 호출되는지 잠깐 알아볼까요? 유저 공간에서 다음과 같이 open 함수를 호출하면 “/dev/devices” 파일에 대한 핸들을 가져온다고 알고 있습니다. 파일 입출력 프로그램에서 많이 쓰이죠.
int main(int argc, char **argv) 
{
int fd;
fd = open(“/dev/devices”, O_RDONLY);

if (fd == -1)
         printf ("fd open Error.... \n");
else
         printf ("fd open success...!!! fd is : %d \n" , fd);
 
close(fd);
}

그런데 위 코드에서 open이란 함수를 유저 공간에서 호출하면 커널 입장에서 어떤 동작을 하죠? open에 해당하는 시스템 콜이 실행됩니다. 이 후 커널 공간에서는 (struct file *)란 자료구조인 파일 디스크립터를 생성합니다. 이 파일 디스크립터가 유저 공간에서 선언된 fd에 대응하는 거죠.  get_unused_fd_flags 함수는 이 파일 디스크립터를 할당하는 동작을 수행합니다. 이번 장은 매크로에 대한 내용을 다루므로 파일 디스크립터에 대한 자세한 내용은 가상 파일 시스템 챕터를 참고하세요.

그럼 다시 get_unused_fd_flags  함수 분석으로 돌아갈게요. 
3 return __alloc_fd(current->files, 0, rlimit(RLIMIT_NOFILE), flags);

3번째 줄 코드를 보면 current 변수로 current->files 멤버에 접근해서 __alloc_fd 함수 첫 번째 파라미터로 전달합니다. 코드를 조금 눈여겨보면 조금 이상한 점이 보이지 않나요? 난감하게도 어느 코드에도 current를 지역변수나 전역 변수로 선언한 흔적이 없습니다.

이번에는 __put_task_struct란 함수 코드 조각을 같이 볼게요.
1 void __put_task_struct(struct task_struct *tsk)
2 {
3 WARN_ON(!tsk->exit_state);
4 WARN_ON(atomic_read(&tsk->usage));
5 WARN_ON(tsk == current);
 
5번째 줄을 보면 __put_task_struct 함수로 전달된 struct task_struct 타입 tsk 파라미터와 current가 같은지 체크를 합니다. 이번도 마찬가지입니다. 함수 내 current란 변수를 선언한 흔적이 없습니다. 그런데 갑자기 current란 변수가 나타났습니다.

5번째 줄 코드에서 WARN_ON이란 매크로가 보이네요. 이 매크로는 WARN_ON 매크로 내 조건 코드가 true면 WARN 코드를 실행합니다.  

위에서 2가지 예시는 빙산의 일각에 불과합니다. current란 변수는 리눅스 커널 코드에서 굉장히 많이 볼 수 있거든요. 그래서 이 코드를 정확히 이해해야 커널 코드를 읽는 데 문제가 없겠죠.

그럼 current 코드에 대해서 알아볼게요. current는 현재 구동 중인 프로세스의 태스크 디스크립터입니다. 구조체는 struct task_struct이고 포인터형 변수입니다. 그래서 current->comm, current->files 형태로 각 멤버에 접근합니다. 

여기서 태스크 디스크립터란 어려운 용어가 나오는데요. 태스크 디스크립터를 잠깐 소개할게요.
임베디드 시스템에서 TCB(Task Control Block)란 용어 들어오신 적 있나요? 프로세스의 상세 정보(이름, 메모리 정보, 실행 시간)을 담고 있는 자료 구조입니다.

리눅스 커널에서 TCB를 태스크 디스크립터라고 하며 이 자료 구조는 include/linux/sched.h 해더 파일을 보시면 됩니다.
struct task_struct {
#ifdef CONFIG_THREAD_INFO_IN_TASK
/*
 * For reasons of header soup (see current_thread_info()), this
 * must be the first element of task_struct.
 */
struct thread_info thread_info;
#endif
volatile long state; /* -1 unrunnable, 0 runnable, >0 stopped */
void *stack;

상세 내용은 커널 자료 구조 챕터에서 더 살펴보니 참고하세요.

이제 다시 current 코드로 돌아갈게요. 이 변수는 struct task_struct 구조체이며 포인터형이라고 했죠? 그럼 다음과 같이 선언됐다고 봐도 좋겠죠?
struct task_struct *current;

태그 : , , , ,
트랙백(0)핑백(8)덧글(0)

[Linux][Kernel] BUG 매크로 [라즈베리파이][커널]매크로분석



BUG 매크로는 보통 소프트웨어적으로 심각한 오류 상태라 더는 실행할 수 없다고 판단할 때 호출 합니다. 혹시 소프트웨어 공학에서 ASSERT란 단어 들어 보신 적 있나요? 보통 포인터가 NULL일 때 ASSERT를 호출하죠. 예제 코드는 다음과 같습니다.
void trace_kernel_process_name(void *param)
{
   if( !param )
      ASSERT(1);

  printk(“ process name: %s pid: %d \n”, current->comm, current->pid)
}
 
리눅스 커널에서는 ASSERT 대신 BUG()를 씁니다. 그리고 panic이란 함수도 비슷한 역할을 수행합니다.
BUG나 panic이란 함수를 호출하면 커널 크래시가 발생하는 것이지요. 커널 크래시가 발생한 시스템 정보를 출력하고 리셋되거나 그 화면에서 멈춰있죠.
void trace_kernel_process_name(void *param)
{
   if( !param )
      BUG();

  printk(“ process name: %s pid: %d \n”, current->comm, current->pid)
}
 
BUG와 더불어 BUG_ON매크로도 많이 쓰는데요, BUG_ON 매크로 내의 조건이 1이면 BUG를 호출하는 것입니다. BUG_ON(조건) 이렇게 표현할 수도 있겠네요.

리눅스 커널 로그를 검색하면 BUG()와 BUG_ON(1)과 같은 코드가 지뢰같이 엄청 많이 깔려 있어요. 다른 용어로 "버그 혹은 패닉 맞았다" 이렇게 표현을 합니다. 

그럼 커널 크래시가 발생했을 때 검은색 배경에 흰색 메시지를 출력하는데요. 이 때 출력하는 에러 메시지를 하나 소개할게요. 다음은 BUG가 실행됐을 때 출력되는 에러 메시지입니다.
[22.423007][1] ------------[ cut here ]------------
[22.423027][1] kernel BUG at /home001/austindh.kim/src/kernel/mm/slub.c:3485!
[22.423047][1] Internal error: Oops - BUG: 0 [#1] PREEMPT SMP ARM
[22.423064][0] Modules linked in: texfat(PO)
[22.423093][1] CPU: 1 PID: 1 Comm: init  
[22.423110][1] task: e3688040 ti: e3682000 task.ti: e3682000
[22.423133][1] PC is at kfree+0x13c/0x280
[22.423152][1] LR is at gs_free_req+0x14/0x2c
[22.423171][1] pc : [<c0220a10>]    lr : [<c06bb1dc>]    psr: 40070093
[22.423171][1] sp : e3683e38  ip : 00000000  fp : ae30b638
[22.423193][1] r10: 00000000  r9 : df615540  r8 : 00000200
[22.423209][1] r7 : 00000100  r6 : 6b6b6b6b  r5 : df63d840  r4 : e7953968
[22.423224][1] r3 : 40000000  r2 : e7953968  r1 : 40000000  r0 : e3bb9000
[22.423240][1] Flags: nZcv  IRQs off  FIQs on  Mode SVC_32  ISA ARM  Segment none
[22.423255][1] Control: 10c0383d  Table: 2e0cc06a  DAC: 00000051
[22.423270][1] Process init (pid: 1, stack limit = 0xe3682210)
[22.423285][1] Stack: (0xe3683e38 to 0xe3684000)

그럼 각 에러 메시지의 의미를 간단히 알아볼까요?

[1]: 커널 크래시가 발생한 코드 정보입니다. 친절하게 slub.c 파일 3485라인에서 커널 크래시가 발생했다고 알려주네요.
[22.423027][1] kernel BUG at /home001/austindh.kim/src/kernel/mm/slub.c:3485!

[2]: 모듈 타입으로 로딩한 디바이스 드라이버를 출력합니다.
[22.423064][0] Modules linked in: texfat(PO)
 
[3]: 커널 크래시가 발생했을 때 CPU 번호는 1이고 프로세스 이름은 init pid는 1입니다. 그리고 해당 프로세스의 태스크 디스크립터는 e3688040라고 알려줍니다.
[22.423093][1] CPU: 1 PID: 1 Comm: init  
[22.423110][1] task: e3688040 ti: e3682000 task.ti: e3682000
 
[4]: 커널 크래시가 발생했을 때 레지스터 정보를 출력합니다.
[22.423133][1] PC is at kfree+0x13c/0x280
[22.423152][1] LR is at gs_free_req+0x14/0x2c
[22.423171][1] pc : [<c0220a10>]    lr : [<c06bb1dc>]    psr: 40070093
[22.423171][1] sp : e3683e38  ip : 00000000  fp : ae30b638
[22.423193][1] r10: 00000000  r9 : df615540  r8 : 00000200
[22.423209][1] r7 : 00000100  r6 : 6b6b6b6b  r5 : df63d840  r4 : e7953968
[22.423224][1] r3 : 40000000  r2 : e7953968  r1 : 40000000  r0 : e3bb9000
 
위 정보를 바탕으로 커널 slub.c 파일의 3485라인 코드를 보니 역시 BUG_ON이 실행됐습니다. 코드를 잠깐 보면 해제하려는 메모리를 페이지 디스크립터로 변환했는데 페이지 디스크립터 정보에 문제가 있어 발생한 커널 크래시임을 알 수 있습니다.
3473 void kfree(const void *x)
3474{
3475 struct page *page;
3476 void *object = (void *)x;
3477
3478 trace_kfree(_RET_IP_, x);
3479
3480 if (unlikely(ZERO_OR_NULL_PTR(x)))
3481 return;
3482
3483 page = virt_to_head_page(x);
3484 if (unlikely(!PageSlab(page))) {
3485 BUG_ON(!PageCompound(page));
 
그럼 BUG 매크로 코드를 분석할 시간입니다. 다음 코드를 보시면 아시겠지만 BUG란 매크로는 리눅스 커널보다는 ARM 프로세서를 제어하는 어셈블리 코드로 구성돼 있습니다. 
[arch/arm/include/asm/bug.h]
#define BUG() _BUG(__FILE__, __LINE__, BUG_INSTR_VALUE)

#define __BUG(__file, __line, __value) \
do { \
asm volatile("1:\t" BUG_INSTR(__value) "\n"  \
".pushsection .rodata.str, \"aMS\", %progbits, 1\n" \
"2:\t.asciz " #__file "\n"  \
".popsection\n"  \
".pushsection __bug_table,\"a\"\n" \
".align 2\n" \
"\t.hword " #__line ", 0\n" \
".popsection"); \
unreachable(); \
} while (0)

#define BUG_INSTR_VALUE 0xe7f001f2

BUG 매크로는 __BUG 매크로로 치환되며 __BUG 매크로에서는 0xe7f001f2란 기계어를 실행합니다. 0xe7f001f2란 ARM 프로세스가 식별할 수 없는 코드를 실행하여 ARM 프로세스의 undefined instruction 익셉션을 유발하는 동작이죠.

리눅스 커널 코드에서 BUG, BUG_ON을 보면 심각한 시스템 오류가 있는 상태일 때 실행하는 코드이고 위와 같은 코드 흐름으로 undefined instruction 익셉션으로 커널 크래시를 유발한다는 점을 기억하세요.

여기서 BUG 매크로를 호출하는 코드를 지우면 커널 크래시가 발생 안 하고 계속 커널은 실행이 될 텐데 굳이 BUG 매크로를 추가한 이유가 뭔지 모르겠다고 생각할 수도 있습니다. 하지만 BUG 매크로가 없으면 커널은 이후 다양한 증상으로 오동작(락업, 랜덤 커널 크래시)할 가능성이 매우 높기 때문에 오히려 문제 원인을 알아내기가 더 힘듭니다. 그러니 BUG 매크로가 실행되어 커널 크래시가 발생하면 어떤 조건으로 BUG가 실행됐는지 차근차근 분석하며 문제 원인을 잡는 것이 중요합니다.
태그 : , , , ,
트랙백(0)핑백(8)덧글(0)

[Linux][Kernel] WARN 매크로 [라즈베리파이][커널]매크로분석


WARN 매크로는 코드 흐름에 소프트웨어적인 오류가 있을 때 실행합니다. 그래서 소스 코드를 보다가 WARN() 매크로를 보면 뭔가 논리적인 오류가 있는 조건이라고 봐야겠죠.

WARN 매크로를 어떤 함수에서 실행되면 시스템 정보를 커널 로그로 출력합니다.
1. 콜스택
2. 현재 수행 중인 프로세스 정보: CPU번호, 프로세스 이름, pid
3. 함수 이름과 라인 정보

하지만 커널 시스템에 심각한 오류가 있는 상태가 아니라 판단해서 에러 메시지만 출력하고 시스템을 계속 구동시킵니다.

그럼 새로운 드라이버 코드를 짰는데 WARN 매크로가 실행되면 어떻게 해야 할까요? 시스템에 치명적인 에러는 아니라 그냥 둬야 할까요? 그렇지 않습니다. WARN 매크로는 시스템에 뭔가 논리적인 오류가 있는 상태이므로 반드시 잡아야 합니다.

그럼 WARN 매크로가 어떤 에러 메시지를 출력하는지 하나 예를 들어볼까요? 다음은 리눅스 커널 커뮤니티에서 자주 볼 수 있는 에러 메시지입니다. 물론 WARN 매크로가 실행된 후 출력하는 에러 메시지죠.
[출처: https://www.unix.com/programming/148285-what-unbalanced-irq.html
https://www.linuxquestions.org/questions/programming-9/problem-with-interrupt-handle-770992/]

WARNING: at kernel/irq/manage.c:225 __enable_irq+0x3b/0x57()
Unbalanced enable for IRQ 4
Modules linked in: svsknfdrvr [last unloaded: osal_linux]
Pid: 634, comm: ash Tainted: G W 2.6.28 #1
Call Trace:
[<c011a7f9>] warn_slowpath+0x76/0x8d
[<c012fac8>] profile_tick+0x2d/0x57
[<c011ed72>] irq_exit+0x32/0x34
[<c010f22c>] smp_apic_timer_interrupt+0x41/0x71
[<c01039ec>] apic_timer_interrupt+0x28/0x30
[<c011b2b4>] vprintk+0x1d3/0x300
[<c013a2af>] __setup_irq+0x11c/0x1f2
[<c013a177>] __enable_irq+0x3b/0x57
[<c013a506>] enable_irq+0x37/0x54
[<c68c9156>] svsknfdrvr_open+0x5e/0x65 [svsknfdrvr]
[<c016440a>] chrdev_open+0xce/0x1a4
[<c016433c>] chrdev_open+0x0/0x1a4
[<c01602f7>] __dentry_open+0xcc/0x23a
[<c016049a>] nameidata_to_filp+0x35/0x3f
[<c016b3c5>] do_filp_open+0x16f/0x6ef
[<c0278fd5>] tty_write+0x1a2/0x1c9
[<c0160128>] do_sys_open+0x42/0xcb

위 로그는 아래 __enable_irq 함수의 6번째 줄 코드가 실행될 때 출력합니다.
1 void __enable_irq(struct irq_desc *desc)
2 {
3 switch (desc->depth) {
4 case 0:
5 err_out:
6 WARN(1, KERN_WARNING "Unbalanced enable for IRQ %d\n",
7      irq_desc_get_irq(desc));
 
인터럽트 디스크립터의 (struct irq_desc *)desc->depth 멤버는 인터럽트를 enable 할 때 0, disable 할 때 1을 설정하거든요. 그런데 아래 6번째 줄 코드는 인터럽트를 2번 enable 했을 때 실행합니다.

콜스택을 보면 __enable_irq란 함수에서 뭔가 오류가 생긴 것 같습니다. 에러 메세지를 유심히 보면서 어디서 오류가 생겼는지 점검해야겠죠.

그럼 해당 인터럽트를 어떤 이유인지 모르겠지만 두 번 enable했기 때문에 해당 오류 메시지가 출력된 것이죠. 여기서 desc는 인터럽트 디스크립터란 구조체이고요. 인터럽트에 대한 속성을 저장하고 있는 자료구조입니다.

그래서 이런 WARN 매크로가 출력될 때는 다음과 같은 패치 코드를 추가하여 해당 인터럽트를 enable, disable를 언제, 누가 하는지 점검할 필요가 있습니다. 다음 패치를 작성하여 컴파일 후 커널 이미지를 보드에 다운로드하고 실행시키는 것이죠. 참고로, 다음 패치는 enable하려는 IRQ 번호가 35번이라고 가정하고 생성했습니다. 문제 증상이 재현될 때 WARN 매크로가 실행되면서 출력되는 콜스택 정보로 범인을 잡는 것이죠.
diff --git a/kernel/irq/manage.c b/kernel/irq/manage.c
index 2f50d76..1c5e1ea 100644
--- a/kernel/irq/manage.c
+++ b/kernel/irq/manage.c
@@ -388,6 +388,8 @@ setup_affinity(unsigned int irq, struct irq_desc *desc, struct cpumask *mask)

 void __disable_irq(struct irq_desc *desc, unsigned int irq)
 {
+       if ( irq == 35 )
+               WARN(1, KERN_WARNING " irq 35 is disbled %d, desc->depth %d \n", irq, desc->depth);
        if (!desc->depth++)
                irq_disable(desc);
 }
@@ -442,6 +444,9 @@ EXPORT_SYMBOL(disable_irq);

 void __enable_irq(struct irq_desc *desc, unsigned int irq)
 {
+       if ( irq == 35 )
+               WARN(1, KERN_WARNING " irq 35 is enabled %d, desc->depth\n", irq, desc->depth);
+
        switch (desc->depth) {
        case 0:
  err_out:

그럼 이제 WARN 매크로 구현부를 잠깐 살펴볼까요?
WARN 매크로 코드를 열어보면 실제 __WARN_printf 매크로로 치환된다는 사실을 알 수 있습니다.
[include/asm-generic/bug.h]
#ifndef WARN
#define WARN(condition, format...) ({ \
int __ret_warn_on = !!(condition); \
if (unlikely(__ret_warn_on)) \
__WARN_printf(format); \
unlikely(__ret_warn_on); \
})
#endif
 
이후 __WARN_printf 매크로는 warn_slowpath_fmt 함수로 치환되는데 이 함수에서 __warn 함수를 호출합니다.
#define __WARN_printf(arg...) warn_slowpath_fmt(__FILE__, __LINE__, arg)
 
warn_slowpath_fmt 함수에서 __warn 함수를 호출할 때 전달하는 파라미터 조금 눈여겨볼 필요가 있습니다. file과 line에는 각각 __FILE__ , __LINE__ 매크로가 전달되고 세 번째 파라미터로는 __builtin_return_address(0) 매크로를 전달합니다. __FILE__과 __LINE__ C 언어에서 제공하는 매크로로 현재 실행 중인 코드의 파일 이름과 코드 라인을 알려줍니다. __builin_return_address는 역시 GCC에서 제공하는 빌트인 매크로인데 자신을 호출한 함수 주소를 저장하고 있죠. ARM lr(r14) 레지스터를 써서 말이죠. 이 매크로는 다음에 조금 더 자세히 살펴볼 예정이니 조금 기다려주세요.
1 void warn_slowpath_fmt(const char *file, int line, const char *fmt, ...)
2 {
3 struct warn_args args;
4
5 args.fmt = fmt;
6 va_start(args.args, fmt);
7 __warn(file, line, __builtin_return_address(0), TAINT_WARN, NULL,
8        &args);
9 va_end(args.args);
10 }
 
WARN 매크로가 실행하면 WARN 매크로가 실행된 순간의 상세 시스템 정보를 출력하는데 이 정보를 출력하는 함수가 __warn이며 구현부는 다음과 같습니다.
1 void __warn(const char *file, int line, void *caller, unsigned taint,
2     struct pt_regs *regs, struct warn_args *args)
3 {
4 disable_trace_on_warning();
5
6 pr_warn("------------[ cut here ]------------\n");
7
8 if (file)  //<<--[1]
9 pr_warn("WARNING: CPU: %d PID: %d at %s:%d %pS\n",
10 raw_smp_processor_id(), current->pid, file, line,
11 caller);
12 else
13 pr_warn("WARNING: CPU: %d PID: %d at %pS\n",
14 raw_smp_processor_id(), current->pid, caller);
15
16 if (args)
17 vprintk(args->fmt, args->args);
18
19 if (panic_on_warn) {
20 panic_on_warn = 0;
21 panic("panic_on_warn set ...\n");
22 }
23
24 print_modules();//<<--[2]
25
26 if (regs) //<<--[3]
27 show_regs(regs);
28 else
29 dump_stack();
30
30 print_oops_end_marker();
31
32 /* Just a warning, don't kill lockdep. */
33 add_taint(taint, LOCKDEP_STILL_OK);
34 }

그럼 각각 코드를 조금 더 상세히 살펴볼까요?

[1]: 8번째부터 11번째 줄 코드는 CPU번호와 프로세스의 pid 그리고 파일 이름과 코드 라인 정보를 출력합니다. 그리고 caller변수로 __builtin_return_address(0) 매크로가 전달한 해당 코드를 호출한 함수 주소를 출력합니다.
8 if (file)
9 pr_warn("WARNING: CPU: %d PID: %d at %s:%d %pS\n",
10 raw_smp_processor_id(), current->pid, file, line,
11 caller);
 
[2]: 모듈로 로딩된 디바이스 드라이버 정보를 출력합니다.
24 print_modules();
 
[3]: reqs 란 파라미터 상태에 따라 함수 호출이 다른데요. 보통 dump_stack 함수가 호출됩니다. show_regs는 현재 실행 중인 코드의 레지스터 덤프를 출력하고 dump_stack은 콜 스택 정보를 출력합니다.
26 if (regs)
27 show_regs(regs);
28 else
29 dump_stack();
 
여기까지 WARN 매크로가 실행되면 어떤 함수 흐름으로 시스템 정보를 출력하는지 알아봤습니다. WARN 매크로가 실행되면 소프트웨어적인 오류가 있는 상태이니 지나치지 마시고 꼼꼼히 해당 코드 참고해서 코드를 수정해 주세요.
태그 : , , , , , ,
트랙백(0)핑백(8)덧글(0)

[Linux][Kernel] container_of 매크로 [라즈베리파이][커널]매크로분석


이번에는 container_of란 매크로를 배워볼게요. 커널 코드에서 current 매크로 못지않게 많이 활용하는 매크로이니 잘 알아야겠죠. 그럼 다음 샘플 코드를 함께 보면서 container_of란 매크로을 어떻게 활용하는지 살펴볼까요?

다음 wq_barrier_func 함수를 예를 들까요? container_of를 써서 struct wq_barrier *barr 로컬 변수에 어떤 값을 대입하고 있죠.
static struct workqueue_struct *dev_to_wq(struct device *dev)
{
struct wq_device *wq_dev = container_of(dev, struct wq_device, dev);

return wq_dev->wq;
}

위 코드를 읽기 전에 우선 container_of란 매크로를 쉽게 표현해볼까요?
container_of(입력주소, 구조체, 해당 구조체 멤버)

따라서 container_of(dev, struct wq_device, dev)는 코드는 다음과 같이 해석할 수 있습니다.
dev: 입력주소
struct wq_device: 구조체
dev: struct wq_device에 위치한 멤버

container_of의 첫 번째와 세 번째 파라미터는 모두 dev인데, 이 파라미터는 다르게 해석해야 합니다. 세 번째 파라미터는 dev_to_wq함수에서 전달되는 (struct device *) 타입의 dev가 아니고 struct wq_device란 구조체에 위치한 멤버 이름입니다.

struct wq_device 구조체의 정의는 다음과 같으니 참고하세요.
struct wq_device {
struct workqueue_struct *wq;
struct device dev;
};

이렇게 container_of란 매크로에 익숙하지 않은 분들에겐 좀 헷갈리는 코드인데요.

다음과 같이 수정해야 조금 더 가독성이 높지 않을까요? 물론 이렇게 수정한 코드를 빌드 해서 동작시켜도 똑같이 동작합니다.
static struct workqueue_struct *dev_to_wq(struct device *dev_ptr)
{
struct wq_device *wq_dev = container_of(dev_ptr, struct wq_device, dev);
return wq_dev->wq;
}

여기까지 container_of란 매크로를 쉽게 설명을 했는데요. 이 매크로의 구현부를 확인해볼까요? container_of 란 매크로의 구현부는 다음과 같습니다...
1 #define container_of(ptr, type, member) ({ \
2                const typeof( ((type *)0)->member ) *__mptr = (ptr); 
3                (type *)( (char *)__mptr - offsetof(type,member) );})
위에서 ptr은 입력 주소, type은 구조체 그리고 member는 type이란 구조체에 정의된 멤버라고 했죠? 그럼 이 매크로가 위에서 살펴본 샘플 코드에서 어떻게 치환되는지 살펴볼까요?

여기서 세 번째 줄 코드에 offsetof란 매크로가 보입니다. 이 매크로 형식은 다음과 같습니다.
offsetof(구조체,멤버)

container_of 매크로를 이해하기 위해서는 offsetof란 코드를 알아야 합니다. offsetof 코드는 구조체에서 멤버가 위치한 오프셋을 알아내는 매크로입니다. 그런데 struct wq_device란 멤버에서 (struct device *) 타입의 dev란 멤버는 0x8만큼 오프셋에 떨어져 있습니다.
struct wq_device * wq_dev = ({
const struct wq_dev *__mptr = dev;
(struct wq_dev *)( (char *)__mptr - offsetof(struct wq_dev,work) );

여기까지 분석한 내용을 반영하면 다음과 같이 표시할 수 있다는 거죠. __mptr은 입력 주소인데 이 주소에서 오프셋을 빼는 동작입니다.
wq_dev = ({
        const struct device *__mptr = dev;
        (struct wq_device *)( (char *)__mptr - 0x8);
})

이번에는 다른 코드에서 container_of란 매크로를 살펴볼까요?
static void rcu_free_pool(struct rcu_head *rcu)
{
struct worker_pool *pool = container_of(rcu, struct worker_pool, rcu);

ida_destroy(&pool->worker_ida);

첫 번째 파라미터(rcu): 입력 주소
두 번째 파라미터(struct worker_pool): 구조체
세 번째 파라미터(rcu): struct worker_pool 구조체에 위치한 멤버

이번에도 좀 헷갈릴 수 있는 코드이군요.

[kernel/workqueue.c] 파일에 가보면 strut worker_pool 구조체를 볼 수 있는데요.
해당 구조체를 확인하니 역시 rcu란 멤버가 보이죠?
struct worker_pool {
spinlock_t lock; /* the pool lock */
int cpu; /* I: the associated cpu */
int node; /* I: the associated node ID */
//...
struct rcu_head rcu;
} ____cacheline_aligned_in_smp;

그럼 이제 container_of 매크로는 어셈블리 명령어로 어떻게 처리하는지 점검해볼까요? rcu_free_pool 함수 구현부를 어셈블리 코드로 보니 다음과 같군요.
static void rcu_free_pool(struct rcu_head *rcu)
{
80134fc8: e1a0c00d  mov ip, sp
80134fcc: e92dd818  push {r3, r4, fp, ip, lr, pc}
80134fd0: e24cb004  sub fp, ip, #4
80134fd4: e52de004  push {lr} ; (str lr, [sp, #-4]!)
80134fd8: ebff6558  bl 8010e540 <__gnu_mcount_nc>
80134fdc: e1a04000  mov r4, r0  //<<--[1]
struct worker_pool *pool = container_of(rcu, struct worker_pool, rcu);

ida_destroy(&pool->worker_ida);
80134fe0: e240004c  sub r0, r0, #76 ; 0x4c  //<<--[2]
80134fe4: eb0c57f5  bl 8044afc0 <ida_destroy>

이제 그럼 어셈블리 코드에서 container_of를 어떻게 처리하는지 같이 살펴볼까요?

[1]: rcu_free_pool에 전달된 파라미터는 (struct rcu_head*) 타입의 rcu입니다.
ARM 프로세스의 호출 규약에 따라 이 파라미터는 r0 레지스터에 실려 옵니다.

r0를 r4에 이동시키는 명령어입니다. 이 명령어가 실행되면 rcu란 파라미터의 주소는 r4에 위치합니다.

조금 더 깊이 있게 ARM 어셈블리 명령어를 분석하다 보면 어느 정도 패턴이 보이거든요.
이런 패턴의 ARM 어셈블리 명령어를 보면 "아 r0을 r4에 백업시켜 놓고 r0에 어떤 값을 저장하려는 거구나" 라는 생각이 떠오르지 않나요?

어떤 함수를 호출할 때는 파라미터는 r0에 저장한 후 호출하거든요.

[2]: r0에 0x4c을 빼는 연산입니다. 그럼 이 동작은 뭘 의미할까요?
r0 = r0 - 0x4c = (struct rcu_head *rcu 주소) - (struct worker_pool.rcu 멤버 오프셋) 

이렇게 어셈블리 명령어를 분석하니 한 가지 교훈을 얻을 수 있습니다. container_of 매크로를 어떤 코드에서 만나면 두 번째 인자인 구조체에서 세 번째 인자인 해당 구조체 멤버의 오프셋이 얼마인지 계산해야겠죠. 이를 위해 해당 구조체의 선언부를 코드를 열어서 확인하면서 머릿속으로 각 멤버 오프셋이 몇 바이트인지 체크해야 합니다. 그런데 어셈블리 코드를 보면 struct worker_pool 구조체의 rcu 멤버의 오프셋을 이미 알고 있는 듯하네요. GCC 컴파일러가 struct worker_pool 구조체의 rcu 멤버의 오프셋을 계산해서 어셈블리 코드를 생성한 것이지요.

가끔은 C 코드로 어떤 매크로를 읽을 때 보다 어셈블리 명령어가 훨씬 이해 속도가 빠를 때도 있습니다. 그러니 C 코드와 어셈블리 코드를 함께 보는 습관을 갖는 게 좋습니다.

태그 : , , , ,
트랙백(0)핑백(8)덧글(0)

11 [라즈베리파이][커널]매크로분석

         <idle>-0     [000] d.h.  4485.656003: irq_handler_exit: irq=62 ret=unhandled
          <idle>-0     [000] d.h.  4485.656005: irq_handler_entry: irq=62 name=dwc_otg_pcd
          <idle>-0     [000] d.h.  4485.656006: irq_handler_exit: irq=62 ret=unhandled
          <idle>-0     [000] d.h.  4485.656008: irq_handler_entry: irq=62 name=dwc_otg_hcd:usb1
          <idle>-0     [000] d.h.  4485.656016: irq_handler_exit: irq=62 ret=handled
          <idle>-0     [000] d.h.  4485.656254: irq_handler_entry: irq=62 name=dwc_otg
          <idle>-0     [000] d.h.  4485.656257: irq_handler_exit: irq=62 ret=unhandled
          <idle>-0     [000] d.h.  4485.656258: irq_handler_entry: irq=62 name=dwc_otg_pcd
          <idle>-0     [000] d.h.  4485.656260: irq_handler_exit: irq=62 ret=unhandled
          <idle>-0     [000] d.h.  4485.656262: irq_handler_entry: irq=62 name=dwc_otg_hcd:usb1
          <idle>-0     [000] d.h.  4485.656270: irq_handler_exit: irq=62 ret=handled
          <idle>-0     [000] d.h.  4485.658569: irq_handler_entry: irq=92 name=mmc1
          <idle>-0     [000] d.h.  4485.658580: irq_handler_exit: irq=92 ret=handled
          <idle>-0     [000] dnh.  4485.658604: irq_handler_entry: irq=17 name=arch_timer
          <idle>-0     [000] dnh.  4485.658615: irq_handler_exit: irq=17 ret=handled
          <idle>-0     [000] d...  4485.658630: sched_switch: prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=irq/92-mmc1 next_pid=65 next_prio=49
     irq/92-mmc1-65    [000] d.h.  4485.658663: irq_handler_entry: irq=92 name=mmc1
     irq/92-mmc1-65    [000] d.h.  4485.658670: irq_handler_exit: irq=92 ret=handled
     irq/92-mmc1-65    [000] d.h.  4485.658713: irq_handler_entry: irq=92 name=mmc1
     irq/92-mmc1-65    [000] d.h.  4485.658723: irq_handler_exit: irq=92 ret=handled
     irq/92-mmc1-65    [000] d...  4485.658778: sched_switch: prev_comm=irq/92-mmc1 prev_pid=65 prev_prio=49 prev_state=D ==> next_comm=kworker/0:2 next_pid=20114 next_prio=120
     kworker/0:2-20114 [000] d.h.  4485.658787: irq_handler_entry: irq=92 name=mmc1
     kworker/0:2-20114 [000] d.h.  4485.658793: irq_handler_exit: irq=92 ret=handled
     kworker/0:2-20114 [000] d.h.  4485.658796: irq_handler_entry: irq=92 name=mmc1
     kworker/0:2-20114 [000] d.h.  4485.658800: irq_handler_exit: irq=92 ret=handled
     kworker/0:2-20114 [000] d...  4485.658816: sched_switch: prev_comm=kworker/0:2 prev_pid=20114 prev_prio=120 prev_state=R ==> next_comm=irq/92-mmc1 next_pid=65 next_prio=49
     irq/92-mmc1-65    [000] d...  4485.658843: sched_switch: prev_comm=irq/92-mmc1 prev_pid=65 prev_prio=49 prev_state=S ==> next_comm=kworker/u8:2 next_pid=20113 next_prio=120
    kworker/u8:2-20113 [000] d.h.  4485.658865: irq_handler_entry: irq=92 name=mmc1



S   UID   PID  PPID  C PRI  NI   RSS    SZ WCHAN  TTY          TIME CMD
S     0     1     0  0  80   0  6080  7045 -      ?        00:00:02 systemd
S     0     2     0  0  80   0     0     0 -      ?        00:00:00 kthreadd
I     0     4     2  0  60 -20     0     0 -      ?        00:00:00 kworker/0:0H
I     0     5     2  0  80   0     0     0 -      ?        00:00:00 kworker/u8:0
I     0     6     2  0  60 -20     0     0 -      ?        00:00:00 mm_percpu_wq
S     0     7     2  0  80   0     0     0 -      ?        00:00:00 ksoftirqd/0
I     0     8     2  0  80   0     0     0 -      ?        00:00:00 rcu_sched
I     0     9     2  0  80   0     0     0 -      ?        00:00:00 rcu_bh
S     0    10     2  0 -40   -     0     0 -      ?        00:00:00 migration/0
S     0    11     2  0  80   0     0     0 -      ?        00:00:00 cpuhp/0
S     0    12     2  0  80   0     0     0 -      ?        00:00:00 cpuhp/1
S     0    13     2  0 -40   -     0     0 -      ?        00:00:00 migration/1
S     0    14     2  0  80   0     0     0 -      ?        00:00:00 ksoftirqd/1
I     0    16     2  0  60 -20     0     0 -      ?        00:00:00 kworker/1:0H
S     0    17     2  0  80   0     0     0 -      ?        00:00:00 cpuhp/2
S     0    18     2  0 -40   -     0     0 -      ?        00:00:00 migration/2
S     0    19     2  0  80   0     0     0 -      ?        00:00:00 ksoftirqd/2
I     0    21     2  0  60 -20     0     0 -      ?        00:00:00 kworker/2:0H
S     0    22     2  0  80   0     0     0 -      ?        00:00:00 cpuhp/3
S     0    23     2  0 -40   -     0     0 -      ?        00:00:00 migration/3
S     0    24     2  0  80   0     0     0 -      ?        00:00:00 ksoftirqd/3
I     0    26     2  0  60 -20     0     0 -      ?        00:00:00 kworker/3:0H
S     0    27     2  0  80   0     0     0 -      ?        00:00:00 kdevtmpfs
I     0    28     2  0  60 -20     0     0 -      ?        00:00:00 netns
I     0    30     2  0  80   0     0     0 -      ?        00:00:00 kworker/1:1
I     0    32     2  0  80   0     0     0 -      ?        00:00:00 kworker/3:1
S     0    33     2  0  80   0     0     0 -      ?        00:00:00 khungtaskd
S     0    34     2  0  80   0     0     0 -      ?        00:00:00 oom_reaper
I     0    35     2  0  60 -20     0     0 -      ?        00:00:00 writeback
S     0    36     2  0  80   0     0     0 -      ?        00:00:00 kcompactd0
I     0    37     2  0  60 -20     0     0 -      ?        00:00:00 crypto
I     0    38     2  0  60 -20     0     0 -      ?        00:00:00 kblockd
I     0    39     2  0  60 -20     0     0 -      ?        00:00:00 watchdogd
I     0    40     2  0  60 -20     0     0 -      ?        00:00:00 rpciod
I     0    41     2  0  60 -20     0     0 -      ?        00:00:00 xprtiod
I     0    42     2  0  80   0     0     0 -      ?        00:00:00 kworker/u8:1
S     0    44     2  0  80   0     0     0 -      ?        00:00:00 kswapd0
I     0    45     2  0  60 -20     0     0 -      ?        00:00:00 nfsiod
I     0    55     2  0  60 -20     0     0 -      ?        00:00:00 kthrotld
I     0    56     2  0  60 -20     0     0 -      ?        00:00:00 iscsi_eh
I     0    57     2  0  60 -20     0     0 -      ?        00:00:00 dwc_otg
I     0    58     2  0  60 -20     0     0 -      ?        00:00:00 DWC Notificatio
S     0    60     2  0  61 -19     0     0 -      ?        00:00:00 vchiq-slot/0
S     0    61     2  0  61 -19     0     0 -      ?        00:00:00 vchiq-recy/0
S     0    62     2  0  60 -20     0     0 -      ?        00:00:00 vchiq-sync/0
S     0    63     2  0  80   0     0     0 -      ?        00:00:00 vchiq-keep/0
S     0    64     2  0  70 -10     0     0 -      ?        00:00:00 SMIO
S     0    65     2  0   9   -     0     0 -      ?        00:00:00 irq/92-mmc1
S     0    68     2  0  80   0     0     0 -      ?        00:00:01 mmcqd/0
S     0    69     2  0  80   0     0     0 -      ?        00:00:00 jbd2/mmcblk0p2-
I     0    70     2  0  60 -20     0     0 -      ?        00:00:00 ext4-rsv-conver
I     0    71     2  0  60 -20     0     0 -      ?        00:00:00 ipv6_addrconf
S     0    84     1  0  80   0  4548  6730 -      ?        00:00:00 systemd-journal
I     0    91     2  0  60 -20     0     0 -      ?        00:00:00 kworker/2:1H
I     0   111     2  0  80   0     0     0 -      ?        00:00:00 kworker/0:2
S     0   125     1  0  80   0  3376  3639 -      ?        00:00:00 systemd-udevd
I     0   130     2  0  80   0     0     0 -      ?        00:00:00 kworker/3:2
I     0   221     2  0  60 -20     0     0 -      ?        00:00:00 cfg80211
I     0   223     2  0  60 -20     0     0 -      ?        00:00:00 brcmf_wq/mmc1:0
S     0   224     2  0  80   0     0     0 -      ?        00:00:00 brcmf_wdog/mmc1
I     0   256     2  0  80   0     0     0 -      ?        00:00:00 kworker/2:2
S   100   297     1  0  80   0  3920  4319 -      ?        00:00:00 systemd-timesyn
S     0   330     1  0  80   0  2428  1747 -      ?        00:00:00 cron
S   108   332     1  0  80   0  3140  1600 -      ?        00:00:00 avahi-daemon
S     0   339     1  0  80   0  4212  1844 -      ?        00:00:00 systemd-logind
S     0   343     1  0  80   0  2696  5937 -      ?        00:00:00 rsyslogd
S   105   349     1  0  80   0  3680  1652 -      ?        00:00:00 dbus-daemon
S   108   366   332  0  80   0   324  1600 -      ?        00:00:00 avahi-daemon
S     0   368     1  0  80   0  1792   737 -      ?        00:00:00 dhcpcd
S 65534   383     1  0  80   0  2508  1323 -      ?        00:00:00 thd
I     0   399     2  0  80   0     0     0 -      ?        00:00:00 kworker/2:3
S     0   402     1  0  80   0  4088  2540 -      ?        00:00:00 wpa_supplicant
S     0   443     1  0  80   0  7296  9987 -      ?        00:00:00 lightdm
I     0   446     2  0  60 -20     0     0 -      ?        00:00:00 kworker/3:1H
S     0   455     1  0  80   0  2884  1470 -      tty1     00:00:00 login
S     0   462   443  3  80   0 84348 59744 -      tty7     00:00:28 Xorg
I     0   608     2  0  60 -20     0     0 -      ?        00:00:00 kworker/u9:0
S     0   609     1  0  80   0   152   524 -      ?        00:00:00 hciattach
I     0   610     2  0  60 -20     0     0 -      ?        00:00:00 kworker/u9:1
S     0   612     1  0  80   0  3700  1817 -      ?        00:00:00 bluetoothd
S     0   616     1  0  80   0  3612  8759 -      ?        00:00:00 bluealsa
S     0   634     2  0  70 -10     0     0 -      ?        00:00:00 krfcommd
S     0   638   443  0  80   0  7528  8038 -      ?        00:00:00 lightdm
S  1000   646     1  0  80   0  5892  2415 SyS_ep ?        00:00:00 systemd
S  1000   649   646  0  80   0  1456  2853 -      ?        00:00:00 (sd-pam)
S  1000   654   638  0  80   0 13240 13598 poll_s ?        00:00:00 lxsession
S  1000   664   646  0  80   0  3480  1626 SyS_ep ?        00:00:00 dbus-daemon
S  1000   676   455  0  80   0  4048  1967 poll_s tty1     00:00:00 bash
I     0   730     2  0  60 -20     0     0 -      ?        00:00:00 kworker/1:1H
S  1000   732   654  0  80   0   228   949 -      ?        00:00:00 ssh-agent
S  1000   738   646  0  80   0  5928 10341 poll_s ?        00:00:00 gvfsd
S  1000   743   646  0  80   0  6368 14121 futex_ ?        00:00:00 gvfsd-fuse
S  1000   761   654  0  80   0 15592 14158 poll_s ?        00:00:02 openbox
S  1000   764   654  0  80   0 10904 11245 poll_s ?        00:00:00 lxpolkit
S  1000   766   654  1  80   0 27500 39100 poll_s ?        00:00:09 lxpanel
S  1000   767   654  0  80   0 27892 34207 poll_s ?        00:00:01 pcmanfm
S  1000   774     1  0  80   0   228   949 -      ?        00:00:00 ssh-agent
S     0   784     1  0  80   0  7204 10045 -      ?        00:00:00 polkitd
S  1000   804     1  0  80   0  6236  7111 poll_s ?        00:00:00 menu-cached
S  1000   860   646  0  80   0 10552 19099 poll_s ?        00:00:00 gvfs-udisks2-vo
S     0   863     1  0  80   0  8884 14799 -      ?        00:00:00 udisksd
S  1000   870   646  0  80   0  6740 13170 poll_s ?        00:00:00 gvfs-afc-volume
S  1000   880   646  0  80   0  5324  9764 poll_s ?        00:00:00 gvfs-goa-volume
S  1000   884   646  0  80   0  5492  9745 poll_s ?        00:00:00 gvfs-mtp-volume
S  1000   891   646  0  80   0  5820 10138 poll_s ?        00:00:00 gvfs-gphoto2-vo
S  1000   928   646  0  80   0  8260 13301 poll_s ?        00:00:00 gvfsd-trash
I     0   948     2  0  60 -20     0     0 -      ?        00:00:00 kworker/0:1H
S  1000   949   766  8  80   0 186672 179409 poll_s ?      00:01:03 chromium-browse
S  1000   968   949  0  80   0 32128 50824 wait   ?        00:00:00 chromium-browse
S  1000   970   968  0  80   0  7400 50824 poll_s ?        00:00:00 chromium-browse
S  1000  1168   970  1  80   0 85852 96478 futex_ ?        00:00:11 chromium-browse
S  1000  1192   970  2  80   0 124764 104188 futex_ ?      00:00:15 chromium-browse
S  1000  1210   949  0  80   0 57920 70603 poll_s ?        00:00:00 chromium-browse
S  1000  1316   970  4  80   0 131900 105732 futex_ ?      00:00:30 chromium-browse
S  1000  1328   970  0  80   0 79892 86175 futex_ ?        00:00:01 chromium-browse
S  1000  1339   970  0  80   0 79224 86663 futex_ ?        00:00:01 chromium-browse
S  1000  1343   970  0  80   0 92448 93828 futex_ ?        00:00:05 chromium-browse
S  1000  1360   970  0  80   0 91612 88538 futex_ ?        00:00:03 chromium-browse
S  1000  1377   970  1  80   0 104836 101360 futex_ ?      00:00:12 chromium-browse
S  1000  1388   970  0  80   0 92440 90547 futex_ ?        00:00:03 chromium-browse
S  1000  1399   970  0  80   0 87228 86463 futex_ ?        00:00:03 chromium-browse
I     0  1699     2  0  80   0     0     0 -      ?        00:00:00 kworker/1:0
S  1000  1700   766  5  80   0 63844 35010 poll_s ?        00:00:22 geany
S  1000  1703  1700  0  80   0  1384   590 -      ?        00:00:00 gnome-pty-helpe
S  1000  1704  1700  0  80   0  3964  1950 poll_s pts/1    00:00:00 bash
I     0  1724     2  0  80   0     0     0 -      ?        00:00:00 kworker/0:0
S  1000  1762   766  1  80   0 22588 13838 poll_s ?        00:00:02 lxterminal
S  1000  1763  1762  0  80   0  1368   590 -      ?        00:00:00 gnome-pty-helpe
S  1000  1764  1762  0  80   0  3972  1950 wait   pts/0    00:00:00 bash
I     0  1888     2  0  80   0     0     0 -      ?        00:00:00 kworker/u8:2
I     0  1903     2  0  80   0     0     0 -      ?        00:00:00 kworker/1:2
I     0  1965     2  0  80   0     0     0 -      ?        00:00:00 kworker/0:1
R  1000  1967  1764  0  80   0  1184  2240 -      pts/0    00:00:00 ps

  
           CPU0       CPU1       CPU2       CPU3       
 16:          0          0          0          0  bcm2836-timer   0 Edge      arch_timer
 17:       4121       3242       3184       3630  bcm2836-timer   1 Edge      arch_timer
 21:          0          0          0          0  bcm2836-pmu   9 Edge      arm-pmu
 23:        158          0          0          0  ARMCTRL-level   1 Edge      3f00b880.mailbox
 24:         14          0          0          0  ARMCTRL-level   2 Edge      VCHIQ doorbell
 46:         21          0          0          0  ARMCTRL-level  48 Edge      bcm2708_fb dma
 48:          0          0          0          0  ARMCTRL-level  50 Edge      DMA IRQ
 50:          0          0          0          0  ARMCTRL-level  52 Edge      DMA IRQ
 51:        286          0          0          0  ARMCTRL-level  53 Edge      DMA IRQ
 54:       6724          0          0          0  ARMCTRL-level  56 Edge      DMA IRQ
 59:          0          0          0          0  ARMCTRL-level  61 Edge      bcm2835-auxirq
 62:     125072          0          0          0  ARMCTRL-level  64 Edge      dwc_otg, dwc_otg_pcd, dwc_otg_hcd:usb1
 86:        248          0          0          0  ARMCTRL-level  88 Edge      mmc0
 87:       5123          0          0          0  ARMCTRL-level  89 Edge      uart-pl011
 92:       8397          0          0          0  ARMCTRL-level  94 Edge      mmc1
FIQ:              usb_fiq
IPI0:          0          0          0          0  CPU wakeup interrupts
IPI1:          0          0          0          0  Timer broadcast interrupts
IPI2:       9286      13398      12189      15007  Rescheduling interrupts
IPI3:          8         14         11          6  Function call interrupts
IPI4:          0          0          0          0  CPU stop interrupts
IPI5:        219        113        205        225  IRQ work interrupts
IPI6:          0          0          0          0  completion interrupts
Err:          0



  
트랙백(0)덧글(0)

라즈베리파이(Raspberry Pi) 한글 설정 라즈베리파이_꿀팁

http://cccding.tistory.com/96


트랙백(0)덧글(0)

라즈베리파이(Raspberry Pi) 언어 설정 라즈베리파이_꿀팁

http://www.rasplay.org/?p=3786

오늘은 X-Windows 를 사용하시는 분들 중 한글 사용을 원하시는 분들이 계셔서 X-Windows 에 한글키보드 설치와 설정 법을 포스팅 해 보려 합니다.

 

1. Raspbian system keyboard 및 locale 설정하기.

 

X-Windows 에서 한글키보드를 설치하기 전에 현재 설정된 keyboard 와locale 설정을 수정 또는 확인 합니다.

Raspbian 환경설정 메뉴 진입을 위해 아래 명령어를 입력하자.

sudo raspi-config

key_1

그림 1)

 

1-1 locale 설정하기.

 

Raspbian 메뉴 중 가장 먼저 locale 을 설정 해 보자.

Change_locale 을 선택하면 그림 1-1)과 같이 사용되어질 언어 선택화면이 나타 날 것 이다.

메뉴 중 그림 1-2)와 같이 en_GB.UTF-8 UTF-8, en_US.UTF-8 UTF-8, ko_kr.UTF-8 UTF-8 세가지 언어를 체크선택(space bar) 합니다.

세 가지 메뉴를 모두 선택하는 이유는 Owncloud(참조: 클라우드 설치하기 ) 와 같은 프로그램 이용 시에나 터미널에서 한글을 사용하기 위함이다.

 

그럼 계속해서 아래 그림을 보면서 천천히 locale 설정을 진행 해 보자.

 

key_2

그림 1-1) Raspbian locale 설정 첫 화면

 

key_3

그림 1-2) en_GB.UTF-8 UTF-8, en_US.UTF-8 UTF-8, ko_kr.UTF-8 UTF-8 선택하기

 

터미널에서 한글을 보려면 ko_KR.UTF-8 을 저 처럼 별도의 한글 표기없이 영어를 사용하려면 en_GB 나 en_US 를 선택하기 바란다.

추가로 ko_KR… 을 선택 시에 일부 명령어들 실행 시에 관련 내용이 한글로 표현이 되니 참고하기 바란다.

key_4

그림 1-3)  en_GB.UTF-8 또는 en_US.UTF-8 을 선택 후, <OK> 를 누르자.

 

key_5

그림 1-4) system locale 환경저장 화면

 

1-2. Raspbian keyboard 설정하기

 

1-1. locale 설정이 완료되었으니, 키보드를 설정 해 보자

 

key_6

그림 1-5) Generic 105 key (Intl) PC 를 선택하자

* Tip : Slim 키보드 또는 파이 랩독 사용유저는 Generic 102 key (Intl) PC 를 선택하자.

 

key_7

그림 1-6) Other 를 선택하자

 

key_9

그림 1-7) Korean 을 선택하자

 

key_10

그림 1-9) Korean 아래 Korean – Korean (101/104 key compatibale)을 선택하자

 

key_11

그림 1-11) The default for the keyboard layout 을 선택하자

 

key_12

그림 1-12) No compose key 를 선택하자

 

key_13

그림 1-13) X-windows에서 단축키를 이용하여 terminal을 실행여부를 묻는 화면이다 저는  “no” 를 선택하자.

 

key_14

그림 1-14) keyboard 환경설정 저장화면
자 이제  기본적인 라즈비안 시스템에서 키보드 설정이 마무리 되었다.

그럼 다음은 X-Windows 상에서 한글폰트와 한글키보드를 사용 할 수있다록 해 보자.

 

2. X-Windows 에서 한글(두벌식) 입력기 사용하기 

 

1번 항목을 모두 완료 했다고 하여도 X-Windows 에서 한글을 볼 수는 있겠지만 한글을 입력 할 수는 없다.

X-Windows 상에서 한글을 입력하기 위해서 제공되는 “ibus” 를  설치해 보도록 하자

 

2.1  ibus 설치하기 

 

apt-get install 명령어를 이용하여 ibus 패키지를 설치하자

sudo apt-get install ibus ibus-hangul

key_15

그림 2) ibus 설치하기

 

  • Tip : 기본 debian의 경우, inavi 나 ibus를 설치 시에 위와 같이 ibus-hangul 이라는 추가 명령어를 입력하지 않아도 됩니다.

    하지만, 라즈비안(Raspbian)의 경우 입력기의 변경을 위해 hangul 이라는 추가 명령어를 삽입하시어 설정 시 혼선이 없도록 해 주시는 것이 좋습니다.

 

2-2. ibus 한글(두벌식) 입력기 설정하기 

 

터미널에서  X-Windows 를 실행 합니다.

startx

X_1

그림 2-1)

 

ibus 아이콘 에서 마우스 오른쪽을 클릭하여 설정메뉴로 진입을 합니다.

X_2

그림 2-2) 설정 메뉴 진입하기

 

X_3

그림 2-3) 한글 키보드 등록하기

Tip : 한글 영문 전환은 기본이 Atl + 왼쪽 Shift 키로 설정되어 있습니다.

 

X_4

그림 2-4) 한/영 전환키 변경하기

트랙백(0)덧글(0)
1 2 3 4 5 6 7 8 9 10 다음
rousalome.egloos.com is powered by Egloos. Subscribe to RSS Skin design by egloos.