IRQ 스레드 생성 실습

이번에는 IRQ 스레드를 직접 생성해보고 ftrace를 이용해서 동작을 확인해본다.

 

새로 인터럽트를 만들지 않고 기존의 인터럽트를 이용할 것이다.

기존의 인터럽트에 스레드만 추가한다.

 

그러므로 먼저 적당한 인터럽트를 찾는다.

root@raspberrypi:/home/ejun0/user_procs# cat /proc/interrupts 
           CPU0       CPU1       CPU2       CPU3       
 26:          0          0          0          0     GICv2  29 Level     arch_timer
 27:     157678     140878     179115     172456     GICv2  30 Level     arch_timer
 30:          0          0          0          0     GICv2 107 Level     fe004000.txp
 31:     106802          0          0          0     GICv2  65 Level     fe00b880.mailbox
 34:       6880          0          0          0     GICv2 153 Level     uart-pl011
 35:          2          0          0          0     GICv2 129 Level     vc4 hvs
 38:       4101          0          0          0     GICv2 114 Level     DMA IRQ
 40:          0          0          0          0     GICv2 116 Level     DMA IRQ
 41:       1104          0          0          0     GICv2 117 Level     DMA IRQ
 45:          0          0          0          0     GICv2 141 Level     vc4 crtc
 46:      21697          0          0          0     GICv2 142 Level     vc4 crtc, vc4 crtc
 47:          0          0          0          0     GICv2 133 Level     vc4 crtc
 48:          0          0          0          0     GICv2 138 Level     vc4 crtc
 49:          0          0          0          0  interrupt-controller@7ef00100   0 Edge      vc4 hdmi cec tx
 50:          0          0          0          0  interrupt-controller@7ef00100   1 Edge      vc4 hdmi cec rx
 53:          0          0          0          0  interrupt-controller@7ef00100   4 Edge      vc4 hdmi hpd connected
 54:          0          0          0          0  interrupt-controller@7ef00100   5 Edge      vc4 hdmi hpd disconnected
 55:          1          0          0          0  interrupt-controller@7ef00100   8 Edge      vc4 hdmi cec tx
 56:          0          0          0          0  interrupt-controller@7ef00100   7 Edge      vc4 hdmi cec rx
 59:          0          0          0          0  interrupt-controller@7ef00100  10 Edge      vc4 hdmi hpd connected
 60:          0          0          0          0  interrupt-controller@7ef00100  11 Edge      vc4 hdmi hpd disconnected
 61:        974          0          0          0     GICv2  66 Level     VCHIQ doorbell
 62:     390975          0          0          0     GICv2 158 Level     mmc1, mmc0
 63:          0          0          0          0     GICv2  48 Level     arm-pmu
 64:          0          0          0          0     GICv2  49 Level     arm-pmu
 65:          0          0          0          0     GICv2  50 Level     arm-pmu
 66:          0          0          0          0     GICv2  51 Level     arm-pmu
 69:      46978          0          0          0     GICv2 189 Level     eth0
 70:          0          0          0          0     GICv2 190 Level     eth0
 76:     102721          0          0          0     GICv2 106 Level     v3d
 77:          0          0          0          0     GICv2 175 Level     PCIe PME
 78:      15400          0          0          0  BRCM STB PCIe MSI 524288 Edge      xhci_hcd
IPI0:          0          0          0          0  CPU wakeup interrupts
IPI1:          0          0          0          0  Timer broadcast interrupts
IPI2:        617        849        975        719  Rescheduling interrupts
IPI3:     161747     240316     344402     344478  Function call interrupts
IPI4:          0          0          0          0  CPU stop interrupts
IPI5:      17074      11706      16850       9423  IRQ work interrupts
IPI6:          0          0          0          0  completion interrupts
Err:          0

31번 mailbox가 적당해 보인다. 책에서도 mailbox를 대상으로 하고 있다.

 

* mailbox는 세마포어같이 프로세스 간의 공유변수 역할을 하는 것으로 보인다.

 

linux/drivers/mailbox/bcm2835-mailbox.c에 다음과 같은 함수를 추가해준다.

static irqreturn_t bcm2835_mbox_threaded_irq(int irq, void *dev_id)
{
        void *stack;
        struct thread_info *current_thread;

        stack = current->stack;
        current_thread = (struct thread_info*)stack;

        trace_printk("irq=%d, process: %s \n", irq, current->comm);
        trace_printk("[+] in_interrupt: 0x%08x,preempt_count = 0x%08x, stack=0x%08lx \n",
                (unsigned int)in_interrupt(), (unsigned int)current_thread->preempt_count, (long unsigned int)stack);

        dump_stack();

        return IRQ_HANDLED;
}

 

bcm2835_mbox_irq함수에선 다음과 같이 수정해준다.

IRQ_WAKE_THREAD를 반환하면 IRQ 스레드를 깨워주기 때문이다.

static irqreturn_t bcm2835_mbox_irq(int irq, void *dev_id)
{
        ...
        //return IRQ_HANDLED;
        return IRQ_WAKE_THREAD;
}

 

bcm2835_mbox_probe에선 devm_request_irq대신 devm_request_threaded_irq를 이용해서 위에서 만든 bcm2835_mbox_threaded_irq함수를 등록해준다.

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);

        ret = devm_request_threaded_irq(dev, platform_get_irq(pdev, 0),
                bcm2835_mbox_irq, bcm2835_mbox_threaded_irq, 0, dev_name(dev), mbox);
        ...
}

 

다 되었다! 이제 리눅스를 빌드하자

---

 

이제 ftrace를 설정하고 로그를 확인한다.

 

아래의 쉘 스크립트를 실행하면 ftrace가 설정된다.

#!/bin/bash

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

echo 0 > /sys/kernel/debug/tracing/events/enable
sleep 1
echo "events disabled"

echo secondary_start_kernel > /sys/kernel/debug/tracing/set_ftrace_filter
sleep 1
echo "set_ftrace_filter init"

echo function > /sys/kernel/debug/tracing/current_tracer
sleep 1
echo "function tracer enabled"

echo bcm2835_mbox_threaded_irq bcm2835_mbox_irq > /sys/kernel/debug/tracing/set_ftrace_filter
sleep 1
echo "set_ftrace_filter enabled"

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/events/sched/sched_switch/enable
echo 1 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable

sleep 1
echo "event enabled"

echo 1 > /sys/kernel/debug/tracing/options/func_stack_trace
echo 1 > /sys/kernel/debug/tracing/options/sym-offset
echo "function stack trace enabled"

echo 1 > /sys/kernel/debug/tracing/tracing_on
echo "tracing_on"

그리고 로그를 출력하면... 

이렇게 나온다.

     kworker/0:1-35      [000] d.h..   888.798169: irq_handler_entry: irq=31 name=fe00b880.mailbox
     kworker/0:1-35      [000] d.h..   888.798171: bcm2835_mbox_irq+0x14/0x90 <-__handle_irq_event_percpu+0x8c/0x204
     kworker/0:1-35      [000] d.h..   888.798173: <stack trace>
 => __handle_irq_event_percpu+0x8c/0x204
 => handle_irq_event+0x74/0xe4
 => handle_fasteoi_irq+0xa8/0x208
 => handle_domain_irq+0x6c/0x88
 => gic_handle_irq+0x88/0x9c
 => __irq_svc+0x4c/0x64
 => _raw_spin_unlock_irqrestore+0x4c/0x58
 => __mod_timer+0x2c8/0x474
 => schedule_timeout+0x94/0x17c
 => do_wait_for_common+0xbc/0x178
 => wait_for_completion_timeout+0x40/0x6c
 => rpi_firmware_property_list+0xf4/0x26c
 => rpi_firmware_property+0x70/0x118
 => raspberrypi_fw_get_rate+0x58/0x88
 => clk_recalc+0x44/0x88
 => clk_change_rate+0x108/0x468
 => clk_core_set_rate_nolock+0x184/0x258
 => clk_set_rate+0x40/0x164
 => _set_opp+0x33c/0x570
 => dev_pm_opp_set_rate+0x100/0x23c
 => set_target+0x38/0x3c
 => __cpufreq_driver_target+0x184/0x240
 => od_dbs_update+0xcc/0x178
 => dbs_work_handler+0x3c/0x68
 => process_one_work+0x224/0x554
 => worker_thread+0x6c/0x5d0
 => kthread+0x158/0x174
 => ret_from_fork+0x14/0x20
 => 0
     kworker/0:1-35      [000] d.h..   888.798176: sched_wakeup: comm=kworker/0:1 pid=35 prio=120 target_cpu=000
     kworker/0:1-35      [000] d.h..   888.798177: irq_handler_exit: irq=31 ret=handled
     kworker/0:1-35      [000] dnh..   888.798181: sched_wakeup: comm=irq/31-fe00b880 pid=38 prio=49 target_cpu=000
     kworker/0:1-35      [000] d....   888.798188: sched_switch: prev_comm=kworker/0:1 prev_pid=35 prev_prio=120 prev_state=R ==> next_comm=irq/31-fe00b880 next_pid=38 next_prio=49
 irq/31-fe00b880-38      [000] .....   888.798192: bcm2835_mbox_threaded_irq+0x14/0xa4 <-irq_thread_fn+0x2c/0x8c
 irq/31-fe00b880-38      [000] .....   888.798193: <stack trace>
 => irq_thread_fn+0x2c/0x8c
 => irq_thread+0x1d0/0x2c8
 => kthread+0x158/0x174
 => ret_from_fork+0x14/0x20
 => 0
 irq/31-fe00b880-38      [000] .....   888.798196: bcm2835_mbox_threaded_irq+0x0/0xa4: irq=31, process: irq/31-fe00b880 
 irq/31-fe00b880-38      [000] .....   888.798199: bcm2835_mbox_threaded_irq+0x0/0xa4: [+] in_interrupt: 0x00000000,preempt_count = 0x00000000, stack=0xc236e00

 

 

 

함수 호출 흐름을 살펴보면, kworker 스레드가 _raw_spin_unlock_irqrestore를 실행 중에 인터럽트가 발생해서 __irq_svc 레이블이 실행되었다.

 

그후 쭉 아래로 내려가 보면 sched_wakeup: comm=irq/31-fe00b880 ... 가 보이는데,

mailbox인터럽트의 IRQ 스레드인 irq/31-fe00b880 프로세스를 깨우는 동작이다.

 

그리고 "irq/31-fe00b880" IRQ 스레드로 스케줄링된 후,  위에서 만든 bcm2835_mbox_threaded_irq 함수가 호출된다.

 

trace_printk로 출력한 마지막 줄은 아래와 같은데,

[+] in_interrupt: 0x00000000,preempt_count = 0x00000000, stack=0xc236e000

 

in_interrupt가 0인걸 보면 인터럽트 컨텍스트가 아닌 걸 알 수 있다.

또한, preempt_count가 0x10000(HARDIRQ_OFFSET)이면 인터럽트 컨텍스트인데 이것으로도 아닌 걸 알수 있다.