[리눅스커널] 디버깅: TRACE32: 모듈 타입 드라이버 심벌(*.ko)을 로딩해 깨진 콜 스택 복원 !

소개

실전 디버깅을 하다보면, 종종 모듈 타입 디바이스 드라이버에서 크래시가 발생할 때가 있습니다.

크래시가 발생하면 먼저 어떤 콜 스택인지 파악하는 경우가 많습니다. 문제는 이 때 TRACE32로 콜 스택 복원을 시도해도 제대로 콜 스택이 출력되지 않는다는 사실입니다.

그 이유는 무엇일까요? 바로 모듈 타입 드라이버의 심벌 정보가 없기 때문입니다.

이번 포스트에서는 TRACE32로 모듈 타입 디바이스 드라이버의 심벌을 로딩하는 방법을 소개합니다.

TRACE32에서 드라이버 모듈 로딩하기

아래 스크린 샷은 Arm64 아키텍처의 함수 호출 규약에 따라 레지스터를 세팅 한 후 출력되는 콜 스택입니다.

 

el1_dbg 라는 레이블이 보이니 BUG() 매크로 함수를 호출해 크래시가 발생한 듯합니다. 그런데 002번째 줄을 보면 이상한 주소만 보이지 함수의 심벌 정보가 보이지 않습니다. 콜 스택이 깨져 보일 때의 화면입니다.

이 상황에서 디바이스 드라이버 모듈을 로딩해 제대로 콜 스택을 출력하는 방법을 설명드리겠습니다.

TRACE32에서 모듈 파일 로딩하기

먼저, 다음 화면과 같이 TRACE32 메뉴 중에 'Linux > Display Modules'을 선택합니다.

 

그럼, 2개의 디바이스 드라이버 모듈이 보일 것입니다. 이 중 첫 번째 모듈을 선택한 다음에, Load Module Symbols을 선택합니다.

그 다음에는 모듈로 생성된 디바이스 드라이버 *.ko 파일을 지정하라는 팝업이 출력됩니다.

이 때 *.ko 파일을 선택합니다.

 

제대로 복원된 콜 스택 확인하기

모듈 파일을 로딩하니 제대로 콜 스택이 출력됩니다.

 

콜 스택을 보니 대략 다음과 같은 정보를 확인할 수 있습니다.

    * 'insmod' 명령어를 실행해 모듈 타입 디바이스 드라이버가 설치되는 과정이다. 

    * init_module() 함수에서 BUG() 함수를 실행해 커널 패닉이 발생했다.

위와 같은 콜 스택으로 모듈식 드라이버가 크래시가 발생하는 경우는 크게 2가지로 분류될 수 있습니다. 

   * 드라이버 모듈을 빌드할 때 컨피그가 제대로 설정돼 있지 않음 

   *.ko 파일에 시그니처(Signature)가 제대로 포함돼 있지 않음

보통 커널 로그에서 에러 정보를 출력해주니 이 정보를 파악해서 후속 조치를 취하면, 문제는 바로 해결됩니다.

끝맺음

리눅스 시스템의 구성하는 방식에 따라 다르지만, 어떤 시스템에서는 상당히 많은 모듈 타입 드라이버를 사용해 드라이버가 실행됩니다. 하나의 업체가 커널 드라이버를 책임지는게 아니라, 여러 드라이버 업체가 개발한 드라이버를 동적으로 로딩하는 프로젝트가 있죠.

이 때 활용하면 좋은 디버깅 팁이니, 잘 활용하셔서 즐겁게 디버깅하시길 빕니다.

Happy, Debugging!

덧글

[HokiMin]

안녕하세요 어스틴님.
포스팅을 보고 평소의 궁금했던 내용이 떠올라서 질문을 드립니다.

워크큐를 사용해서 키 인터럽트 드라이버를 만들었고 insmod로 *.ko 모듈을 동적으로 커널에 로드를 했습니다.

DECLARE_WORK(work, fn)

위의 매크로를 통해 등록된 인터럽트 후반부 처리 함수(fn)의 콜스텍을 보고 싶었습니다.

그런데 생각해보니 드라이버의 심벌 정보가 없기 때문에 dump_stack이나 function_filter와 같은 걸로 콜스텍을 볼 수 없을 거라는 것을 깨달았습니다.
(실제로 콜스텍이 안나왔던 것으로 기억합니다.)

위의 TRACE32의 경우와 마찬가지로 심볼정보를 동적으로 로드해서
ftrace로 *.ko 모듈의 콜스텍을 볼 수 있는 방법이 있을까요?

[AustinKim]

안타깝게도 insmod로 설치되는 디바이스 드라이버의 콜 스택은 심벌 형태로는 보기 어렵습니다.
대신 아래 포스트에서 소개한 방법을 활용하면, 콜 스택을 볼 수 있습니다.(함수 심벌은 표시되지 않음)

http://rousalome.egloos.com/10016709

그럼, 즐거운 주말 보내세요.

[HokiMin]

printk를 이용하면 손쉽게 콜스텍을 얻을 수 있군요! 덕분에 원하던 콜스텍을 확인할 수 있었습니다. 답변 감사드립니다.

<idle>-0 [000] d.h. 3418.298218: workqueue_queue_work: work struct=2751f8bf function=workfn_gpio12_fn [rpi_driver] workqueue=1196be36 req_cpu=4 cpu=0
<idle>-0 [000] d.h. 3418.298220: workqueue_activate_work: work struct 2751f8bf
...
kworker/0:2-145 [000] .... 3418.299955: workqueue_execute_start: work struct 2751f8bf: function workfn_gpio12_fn [rpi_driver]
kworker/0:2-145 [000] .... 3418.299957: printk <8017f494> <-workfn_gpio12_fn <7f61c254>
kworker/0:2-145 [000] .... 3418.299978: <stack trace>
=> printk <8017f498>
=> workfn_gpio12_fn <7f61c254>
=> process_one_work <8013c56c>
=> worker_thread <8013c8c0>
=> kthread <80142c60>
=> ret_from_fork <801010ac>
=> 0
...
kworker/0:2-145 [000] .... 3418.411291: workqueue_execute_end: work struct 2751f8bf

[AustinKim]

참고로, 해당 드라이버를 insmod하기 전에는 해당 심볼을 찾을 수 없다며 발생하는 커널 패닉은 라즈베리 파이(정확히 라즈비안)에서만 일어납니다. 다른 리눅스 시스템(안드로이드, 기타 등등)에서는 발생하지 않아요. 라즈비안이 교육용으로 제작되서 안정성이 약간 떨어지는 면이 있거든요.

이점 참고하세요.

[HokiMin]

아하 그렇군요. 좋은 정보 알려주셔서 감사합니다 ^ㅡ^

[AustinKim]

바로 확인이 되서 다행이네요.
그럼 줄거운 주말 보내세요.

[HokiMin]

감사합니다 어스틴님! 좋은 주말 보내세요.

-----------------------------
P.S.

제가 뭔가를 잘못 알고 있었던 것 같습니다.
위의 로그에서 workfn_gpio12_fn 이 함수가 insmod로 동적으로 로드한 드라이버 내부의 함수 심벌인데요,
이게 심벌로 출력이 되는걸 보고 뭔가 이상함을 느꼈습니다.
그래서 혹시나 하는 마음에

echo workfn_gpio12_fn > /sys/kernel/debug/tracing/set_ftrace_filter

이를 쉘스크립트에 추가하고 댜시 실행을 시켜보았습니다.

이로 알아낸 결과는, 해당 드라이버를 insmod하기 전에는 해당 심볼을 찾을 수 없다며 커널 패닉이 일어났고
insmod한 후에는 정상적으로 filter에 등록이 되었고 콜스텍이 출력이 되었습니다.

제가 저번에 콜스텍 확인할 때 무언가 실수를 한 모양입니다 ㅜ.