(1) 디버깅은 문제 해결 능력의 지름길

디버깅 : 오류 해결

 

  1.  디버깅이 중요한 이유

 

이번 절에서 디버깅 방법을 소개하기 전 디버깅이 중요한 이유를 다음 관점으로 알아보겠습니다.

 - 문제 해결 능력

 - 커널 코드 학습 능력

 

필자는 디버깅을 단지 버그를 잡는 과정으로만 보지 않습니다. 리눅스 커널과 드라이버가 정상 동작할 때 자료구조와 함수 호출까지 파악하는 과정을 디버깅이라고 생각합니다. 그 이유를 더 알아볼까요?

  

신입 개발자들은 실전 리눅스 개발에서 어떤 업무를 하는지 궁금해합니다. 임베디드 리눅스는 ‘클라우드 서버’, ‘휴대폰’, ‘자동차’ 까지 다양한 분야에서 쓰고 있습니다. 따라서 실전 개발 업무가 어떻다고 설명하긴 어렵습니다. 그런데 임베디드 리눅스 프로젝트 개발 중 다양한 문제를 겪습니다. 임베디드 리눅스는 활용 분야가 다양하지만 대표적인 문제를 추리면 다음과 같습니다.

 

 

  1.1  BSP 개발자들이 일하는 중 만나는 문제들

 

  1. 부팅 중 커널 크래시 발생

  2. 인터럽트 핸들러를 설정했는데, 호출되지 않음

  3. 시스템 응답 속도가 매우 느려짐

  4. 파일 복사를 하는척만 하고, 복사 안됨

 

  - 커널 로그 또는 메모리 덤프로 원인 파악 가능

  - 위 내용을 분석하는 것 : 커널 디버깅

 

리눅스 드라이버나 핵심 모듈 개발 업체에서 문제 해결 능력을 겸비한 개발자를 애타게 찾고 있습니다.

 

 

 

  1.2  문제 해결 능력을 키우는 지름길

​

먼저 디버깅 능력을 갖춰야 합니다. 문제 발생 원인을 정확히 파악해야 해결 방안을 찾을 수 있기 때문입니다. 

디버깅 능력은 문제 해결 능력 그 자체 이므로 평소에 디버깅을 꾸준히 해서 리눅스 커널을 자주 익혀야 합니다.

 

 

  예를들면, 기존 작은 규모 소프트웨어 프로젝트를 개발할 때는 버그와 관련된 개발자가 디버깅을 했습니다. 바로 자신이 작성한 코드의 논리적 문제점을 분석했습니다. 즉, 프로젝트 개발 도중 해당 코드를 작성한 엔지니어가 버그를 잡았

습니다.

 

  하지만 오픈 소스 시대인 지금은 예전 상황과 다릅니다. 자신이 작성한 코드보다 다른 개발자가 작성한 코드를 더 많이 분석합니다. 우리가 분석하는, 가장 많이 알려진 오픈소스 프로젝트인 리눅스 커널도 다른 개발자가 작성한 코드입니다. 

 

오픈 소스를 개발할 때 디버깅을 단순히 버그를 잡는 과정에서 그치지 말고 한 발짝 더 나가야 합니다. 세부 리눅스 커널 서브 시스템이 정상 동작할 때 다음 내용을 파악할 필요가 있습니다.

 

 - 분석하는 코드가 어떤 콜스택으로 동작하는지 확인

 - 함수가 실행할 때 변경되는 자료 구조

 - 함수가 실행되는 빈도와 실행 시각

 - 실행 중인 코드를 어떤 프로세스가 실행하는지 확인

 

 

 

위와 같은 내용을 잘 알아야 하는 이유는 무엇일까요?

정상 동작 시 함수 호출 흐름과 자료 구조를 알고 있어야 오류나 버그가 발생했을 때 무엇이 문제인지 식별할 수 있기 때문입니다.

 

여러분이 임베디드 리눅스 개발을 하다가 문제가 생기면 대부분 커널 로그를 봅니다. 그런데

디바이스 드라이버 코드에 오류가 있으면 우리가 작성한 드라이버 코드에서 오류 메시지를 출력하지 않습니다. 대부분 디바이스 드라이버가 호출한 커널 함수 내부에서 에러 메시지를 출력합니다. 디바이스 드라이버 코드는 대부분 커널이 지원하는 함수를 호출해 구현하기 때문입니다. 디바이스 드라이버 코드에 오류가 있으면 커널 내부 함수에서 오류 메시지를 출력하는 경우가 많습니다.

 

 

 

  2.  kernel log 예시

 

한 가지 예를 들겠습니다.

신입 개발자 입장에선 굉장히 어려운 커널 로그를 예시로 들었습니다. 하지만 위와 같은 커널 로그는 실전 개발에서 언제든 만날 수 있습니다. 

 

먼저 첫 번째 에러 로그를 보겠습니다.

01 WARNING: at kernel/irq/manage.c:225 __enable_irq+0x3b/0x57()

 

__enable_irq() 함수에서 뭔가 오류 조건을 검출한 듯 합니다. 에러 메세지를 유심히 보면서 어느 코드에서 오류를 유발했는지 분석해볼까요?

 

먼저 콜스택을 어느 코드에서 출력했는지 살펴봅니다. 위 로그는 아래 __enable_irq() 함수 6번째 줄 코드에서 출력합니다.

[https://elixir.bootlin.com/linux/v4.14.70/source/kernel/irq/manage.c]

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 %dn",

7       irq_desc_get_irq(desc));

 

인터럽트 디스크립터 자료구조인 struct irq_desc 구조체 depth 필드는 인터럽트를 enable하면 0, disable 할 때 1을 설정합니다. 만약 4 번째 인터럽트를 활성화하면 4 번째 인터럽트의 인터럽트 디스크립터 depth 필드를 0으로 설정합니다. 그런데 6번째 줄 코드는 인터럽트를 2번 enable 했을 때 실행합니다. 이미 인터럽트를 enable했으면 depth 필드가 0인데 다시 enable했으니 콜스택을 출력합니다.

 

 

WARN() 매크로 함수는 콜스택을 출력합니다.

 

이번에는 어떤 인터럽트를 연속으로 활성화했는지 파악해볼까요?

01 WARNING: at kernel/irq/manage.c:225 __enable_irq+0x3b/0x57()

02 Unbalanced enable for IRQ 4

 

02 번째 줄 로그를 보면 “IRQ 4” 메시지가 보입니다. 정리하면 4번 인터럽트를 두 번 enable했으므로 해당 오류 메시지를 출력했습니다. 여기서 desc는 인터럽트에 대한 속성을 저장하는 인터럽트 디스크립터 구조체입니다.

 

위와 같은 에러 메시지는 인터럽트를 활성화하는 enable_irq() 함수 내부에 논리적 오류가 있어 출력하지 않습니다.  enable_irq() 함수를 호출한 드라이버 코드에 무엇인가 오류가 있을 가능성이 높습니다. 드라이버 코드 레벨에서 4번 인터럽트를 어떻게 2번 연속 활성화하는지 점검해야 합니다. 

 

grep

-r : hawi

-n : line number

 

그런데 에러 메시지는 커널 내부 함수인 __enable_irq() 함수에서 출력했습니다. 만약 정상 동작할 때 struct irq_desc 구조체 depth 필드를 알고 있으면 이제까지 분석한 에러 메시지의 의미를 바로 알 수 있습니다.

 

그러면 위와 같은 문제는 어떻게 해결할까요? 물론 관련 드라이버 코드를 상세히 분석해 힌트를 얻을 수 있습니다. 

 

[https://www.unix.com/programming/148285-what-unbalanced-irq.html]

01 WARNING: at kernel/irq/manage.c:225 __enable_irq+0x3b/0x57()

02 Unbalanced enable for IRQ 4

03 Modules linked in: svsknfdrvr [last unloaded: osal_linux]

 

  커널 에러 메시지를 보면 svsknfdrvr 드라이버 모듈이 보입니다. 먼저 svsknfdrvr 드라이버 코드 분석한 후 논리적인 오류가 있는지 점검해야 합니다. 

 

  만약 필자에게 위와 같은 문제가 할당되면 어떻게 문제를 좁힐까요? svsknfdrvr 드라이버 코드를 분석하면 좋겠지만 드라이버 개발 업체가 드라이버 코드를 공유하지 않고 모듈(ko) 형태로 배포할 수 도 있습니다. 가끔은 자신이 작성한 드라이버는 문제가 없다고 주장할 수 있습니다.

 

대신, 다음과 같은 패치 코드를 입력해 문제 현상을 재현해 커널 로그를 받아보면 됩니다. 커널 로그가 누가 4번 인터럽트를 2번 활성화했는지 알려줄 겁니다.

(물론 패치 코드를 입력한 다음 커널 빌드해 커널 이미지를 설치한 후 다시 재현을 시켜야 합니다.)

 

diff --git a/kernel/irq/manage.c b/kernel/irq/manage.c

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

 

1 void __disable_irq(struct irq_desc *desc, unsigned int irq)

2 {

3 +       if ( irq == 4 )

4 +               WARN(1, KERN_WARNING " irq 4 is disbled %d, desc->depth %d n", irq, desc->depth);

5        if (!desc->depth++)

6                irq_disable(desc);

7 }

@@ -442,6 +444,9 @@ EXPORT_SYMBOL(disable_irq);

8

9 void __enable_irq(struct irq_desc *desc, unsigned int irq)

10 {

11 +       if ( irq == 4 )

12 +               WARN(1, KERN_WARNING " irq 4 is enabled %d, desc->depthn", irq, desc->depth);

13 +

14        switch (desc->depth) {

15        case 0:

16  err_out:

위와 같은 코드를 디버깅 패치라고 부릅니다. 문제의 원인을 좁힐 수 있는 단서를 찾을 수 있습니다. 

 

패치 코드를 설명하겠습니다. __disable_irq() 함수와 __enable_irq() 함수 2 번째 인자는 irq입니다. 인터럽트 번호입니다. 인터럽트 번호가 4일 때 콜스택을 호출하는 코드입니다.

위 패치 코드를 작성해 커널을 빌드하면 4 번 인터럽트를 활성화 혹은 비활성화할 때 콜스택을 커널 로그로 출력합니다. 어떤 코드에서 4 번 인터럽트를 하는지 알 수 있습니다.

 

필자는 리눅스 커널 고수 중 디버깅에 잘 못하는 개발자는 한 번도 만나본 적이 없습니다. 디버깅 능력은 문제 해결 능력 그 자체 이므로 평소에 디버깅을 꾸준히 해서 리눅스 커널을 익힙시다.

 

 

grep

 

 

 

 

 

출처 : Austin Kim님 블로그