[리눅스커널] 인터럽트 후반부 기법은 왜 적용할까?

인터럽트 후반부 기법을 적용하는 이유

인터러트 후반부 기법을 쓰는 이유에 대해 알아보기 전에 커널이 인터럽트를 어떤 방식으로 처리하는지 살펴볼 필요가 있습니다. 5장에서 배운 내용을 정리해보겠습니다.

1. 인터럽트가 발생하면 커널은 실행 중인 프로세스를 멈추고 인터럽트 벡터를 실행해서 인터럽트 핸들러를 실행합니다.

2. 인터럽트 핸들러는 짧고 빨리 실행해야 합니다.

3. 인터럽트를 처리하는 구간이 인터럽트 컨택스트인데 이를 in_interrupt() 함수가 알려줍니다.

인터럽트 후반부 기법을 적용해야 하는 이유는 인터럽트 컨택스트에서 빨리 실행을 끝내야 하기 때문입니다. 인터럽트는 실행 중인 코드를 멈추고 인터럽트를 핸들링하기 때문입니다.

자연스럽게 임베디드 리눅스 개발자뿐만 아니라 임베디드 개발에서 다음과 같은 고민을 하게됐습니다.

인터럽트 핸들러나 인터럽트 컨택스트에서 어떻게 하면 빨리 코드를 처리해야 할까?

여러 고민 끝에 인터럽트가 발생하면 이를 처리할 코드를 2 단계로 나누게 됐습니다. 빨리 실행해야 할 코드는 인터럽트 컨택스트, 실시간으로 빨리 처리하지 않아도 되는 코드는 인터럽트를 핸들링한 다음에 실행하는 것입니다. 이 과정에서 다음과 같은 인터럽트 후반부 처리 기법을 이끌어낸 것입니다.

이를 위해 커널은 다음과 같은 인터럽트 후반부 처리 방식을 지원합니다.

- IRQ 스레드

- Soft IRQ

- 태스크릿

- 워크큐

다음 소절에서는 인터럽트 컨택스트에서 시간이 오래 걸리는 코드를 수행하면 어떤 일이 발생하는지 살펴보겠습니다.

인터럽트 컨택스트에서 많은 일을 하면 어떻게 될까?

인터럽트 후반부 처리 기법을 왜 적용해야 하는지 설명드리기 위해 인터럽트 컨택스트에서 많은 일을 하는 코드를 적용하면 시스템이 어떻게 오작동하는지 소개합니다.

디바이스 드라이버를 개발하다 보면 인터럽트 컨택스트에서 인터럽트 핸들링을 할 때 많은 일을 하는 코드를 입력할 때가 있습니다. 대표적으로 다음과 같은 예를 들 수 있습니다.

- I/O을 시작하는 코드

- 과도한 while loop

- 유저 공간으로uevent를 전달해서 인터럽트 발생을 알림

- 스케줄링을 지원하는 커널 함수 호출

위와 같은 코드를 입력하면 시스템 반응 속도가 아주 느려지거나 평소에 볼 수 없는 오류 메시지를 볼 수 있습니다.

인터럽트 핸들러와 서브 루틴에서 코드를 작성할 때 빨리 실행하는 코드를 입력해야 합니다. 여기서 중요한 의문점이 생깁니다.

인터럽트 컨택스트에서 인터럽트를 핸들링 하는 코드 실행 시간을 어떻게 측정할 수 있을까?

이를 위해 ftrace 기능에서 지원하는 graph_function 트레이서 기능을 써서 인터럽트 핸들링을 할 때 얼마나 시간이 걸리는 지 측정할 필요가 있습니다. 이번 장 디버깅 장에서 이 방식에 대해 소개합니다.

심지어 인터럽트 컨택스트에서 스케줄링을 지원하는 함수를 쓸 경우 커널은 강제 커널 크래시를 유발합니다.

여기서 인터럽트 핸들러에서 많은 일을 하다가 커널 패닉이 발생하는 예를 들어 보겠습니다. 다음 로그는 인터럽트 핸들러 실행 도중 발생한 커널 패닉 로그입니다. 함수가 일렬로 정렬해 있습니다.

01 [21.719319] [callstack mxt_interrupt,2449] task[InputReader]=========

02 [21.719382] BUG: scheduling while atomic: InputReader/1039/0x00010001

03 [21.719417] (unwind_backtrace+0x0/0x144) from (dump_stack+0x20/0x24)

04 [21.719432] (dump_stack+0x20/0x24) from (__schedule_bug+0x50/0x5c)

05 [21.719444] (__schedule_bug+0x50/0x5c) from (__schedule+0x7c4/0x890)

06 [21.719455] (__schedule+0x7c4/0x890) from [<c0845d70>] (schedule+0x40/0x80)

07 [21.719468] (schedule+0x40/0x80) from [<c0843bc0>] (schedule_timeout+0x190/0x33c)

08 [21.719480] (schedule_timeout+0x190/0x33c) from (wait_for_common+0xb8/0x15c)

09 [21.719491] (wait_for_common+0xb8/0x15c) from (wait_for_completion_timeout+0x1c/0x20)

10 [21.719504] (wait_for_completion_timeout+0x1c/0x20) from (tegra_i2c_xfer_msg+0x380/0x958)

11 [21.719517] (tegra_i2c_xfer_msg+0x380/0x958) from (tegra_i2c_xfer+0x314/0x438)

12 [21.719531] (tegra_i2c_xfer+0x314/0x438) from (i2c_transfer+0xc4/0x128)

13 [21.719546] (i2c_transfer+0xc4/0x128) from (__mxt_read_reg+0x70/0xc8)

14 [21.719560] (__mxt_read_reg+0x70/0xc8) from (mxt_read_and_process_messages+0x58/0x1648)

15 [21.719572] (mxt_read_and_process_messages+0x58/0x1648) from (mxt_interrupt+0x78/0x144)

16 [21.719588] (mxt_interrupt+0x78/0x144) from (handle_irq_event_percpu+0x88/0x2ec)

17 [21.719601] (handle_irq_event_percpu+0x88/0x2ec) from (handle_irq_event+0x4c/0x6c)

18 [21.719614] (handle_irq_event+0x4c/0x6c) from (handle_level_irq+0xbc/0x118)

19 [21.719626] (handle_level_irq+0xbc/0x118) from (generic_handle_irq+0x3c/0x50)

20 [21.719642] (generic_handle_irq+0x3c/0x50) from (tegra_gpio_irq_handler+0xa8/0x124)

21 [21.719655] (tegra_gpio_irq_handler+0xa8/0x124) from (generic_handle_irq+0x3c/0x50)

22 [21.719669] (generic_handle_irq+0x3c/0x50) from (handle_IRQ+0x5c/0xbc)

23 [21.719682] (handle_IRQ+0x5c/0xbc) from (gic_handle_irq+0x34/0x68)

24 [21.719694] (gic_handle_irq+0x34/0x68) from (__irq_svc+0x40/0x70)

참고로 위 로그가 동작한 시스템은 엔비디아 Tegra4i SoC 디바이스입니다. 그래서 tegra가 붙은 함수들이 보입니다. 라즈베리파이 이외에 다른 리눅스 시스템에서 인터럽트를 어떻게 처리하는지 알면 좋으니 리눅스 시스템에서 발생한 문제를 소개합니다.

로그를 꼼꼼히 분석하겠습니다. 함수들이 줄 서 있는데 어느 부분 로그부터 읽어봐야 할까요? 함수들이 가장 먼저 실행된 순서로 정렬돼 있으니 가장 아랫부분 로그부터 봐야 합니다. 이제부터 5장에서 배운 내용을 떠 올리면서 로그 분석을 시작합니다.

가장 처음 실행된 함수 로그부터 보겠습니다. 24 번째 줄 코드를 눈으로 따라가 보면 __irq_svc 레이블이 보일 것입니다.

21 [21.719655] (tegra_gpio_irq_handler+0xa8/0x124) from (generic_handle_irq+0x3c/0x50)

22 [21.719669] (generic_handle_irq+0x3c/0x50) from (handle_IRQ+0x5c/0xbc)

23 [21.719682] (handle_IRQ+0x5c/0xbc) from (gic_handle_irq+0x34/0x68)

24 [21.719694] (gic_handle_irq+0x34/0x68) from (__irq_svc+0x40/0x70)

인터럽트가 발생했다는 사실을 알 수 있습니다. 우리는 인터럽트가 발생하면 인터럽트 벡터인 __irq_svc가 실행한다는 것을 5장에서 배웠습니다. 또한 인터럽트 벡터인 __irq_svc 함수부터 실행된 콜스택(함수 흐름)이니 인터럽트 컨택스트입니다.

다음 14~16 번째 로그를 보겠습니다.

14 [21.719560] (__mxt_read_reg+0x70/0xc8) from (mxt_read_and_process_messages+0x58/0x1648)

15 [21.719572] (mxt_read_and_process_messages+0x58/0x1648) from (mxt_interrupt+0x78/0x144)

16 [21.719588] (mxt_interrupt+0x78/0x144) from (handle_irq_event_percpu+0x88/0x2ec)

아래 로그로 인터럽트 핸들러로 mxt_interrupt() 함수가 호출됐다는 사실을 알 수 있습니다.

우리는 5장에서 인터럽트 핸들러는 __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);

리눅스 커널 버전에 따라 인터럽트를 처리하는 함수가 달라질 수 있습니다.

다음 로그를 보겠습니다. 커널 패닉이 발생한 이유를 출력하고 있습니다.