Debuging in linux kernel in RPI4 (printk, dump_stack, ftrace, ctags, cscope)

printk

 

 

사용법

 

동작이나 함수 멤버등을 확인해보고 싶은 함수내에 printk() 함수 사용

커널로그는  /var/log/kern.org 파일에서 확인 가능하다.

 

	printk("[+][debug] message [F: %s, L:%d]: caller:(%pS)\n", 
			__func__, __LINE__, (void *)_builtin_return_address(0));

 

사용 이유

 

printk 함수는 다양한 로그 레벨과 형식을 지원하여 디버깅 및 로깅 목적으로 사용된다.

함수의 심볼정보를 출력하기 위해 사용하는데

함수 주소를 넘겨 %pS로 심볼정보를 출력한다던지, %p를 통해 주소를 출력하는 용도로 사용한다.

심볼정보란?

쉽게 말하면 함수의 메타데이터이고,

함수명,리턴타입, 매개변수 타입 및 개수를 말한다.

 

[+] process: kworker/2:3
[+][debug] message [F:insert_wq_barrier, L:2354] caller(workqueue_cpu_down_callback+0x90/0xac)

/var/log/kern.org 에서 위와 같은 로그를 볼 수 있을것이다.(insert_wq_barrier함수가 호출 된다면. 즉, 워크큐를 사용할 정도의 로드(부하)를 시스템에 준다면)

 

여기서  printk를 실행한 함수는 kworker /2:3이라는 프로세스이고, printk를 호출한 함수는 insert_wq_barrier이다.

또한 insert_wq_barrier함수는 workqueue_cpu_down_callback함수가 호출했다.

 

 

주의할 점

 

만약 printk를 사용한 함수가 매우 자주 호출되는 함수라면 printk를 자주 출력해서 시스템이 락업 걸릴 위험이 있다.

printk는 파일시스템의 도움으로 로그를 콘솔버퍼에 저장하는 세부 동작을 수행하고, 이 동작들을 콘솔 드라이버에서 처리하며, 커널 로그를 저장하는 동작을 백그라운드로 처리한다.

 

 

dump_stack

 

 

사용법

 

헤더파일인 #include를 추가하고

콜 스택을 확인하고 싶은 함수에서 dump_stack(); 을 사용한다.

콜스택이란?
프로그램은 main 함수에서 시작하여 다른 함수들을 호출하며 작동한다.

이때 만약 main 함수에서 a 함수를 호출하고 a 함수에서 b 함수를 호출하게 된다면

l    b    l

l    a    l

l main l

메모리 함수 스택에 다음과 같은 형태로 저장되어 있을 것이다.

이를 콜 스택 이라고 부르는 것 같다. (정확하지 않을 수 있음)

 

dump_stack을 추가한 후 빌드, 설치 과정을 거친다.

커널 로그를 확인해 보자.

 

 

첫번째 줄은 콜스택을 실행한 프로세스 정보

CPU3을 이용중인 PID 498을 갖는 프로세스라는 의미를 포함한다.

해석하는 방법은 맨 아래줄의 ret_fast_syscall함수가 sys_clone함수를 호출하고 sys_clone이 _do_fork를 호출하는 방식으로 스택과 같은 형태로 해석하면 된다.

 

 

주의할 점

 

dump_stack함수 또한 내부적으로 하는 동작이 많기때문에 자주 호출되는 함수에는 사용하면 락업에 걸릴 확률이 printk보다 높다. 해당 함수는 stack pointer 와 frame pointer를 이용해 함수 호출 동작을 추적한다.

 

 

참고

 

함수 원형에서 asmlinkage 사용하는 이유?
보통 함수를 부르고 인자를 넘길때 레지스터를 통해 하는데 arm mips는 레지스터가 남아서 괜찮지만
x86은 그렇지 않아서 이 인자를 넘기는 것을 스택을 통해 하기 위함.

LTO(컴파일러)기능 -> 콜러와 콜리관계에서 링커가 callee가 한번만 사용된다고 판단하면 inline화 한다.
함수나 객체가 inline화 되지않게 막아주는 역할 즉 컴파일러가 무리하게 inline화 하는걸 막는다.

 

 

ftrace (function trace)

 

ftrace 특징

 

인터럽트, 스케줄링 등의 이벤트를 추적할 수 있다.

트레이싱할 함수를 지정하면 코드를 수정하고 커널을 빌드, 설치할 필요가 없다.

함수를 어느 프로세스가 실행하는지 알 수 있다.

함수 실행 시각을 알 수 있다.

다른 디버깅 함수(dump, printk)와 달리 시스템에 큰 영향을 주지 않는다.

 

사용법

 

 

ftrace 설정 파일입니다. ftrace는 커널에 내장되어 있다.

위 파일들에 0 또는 1 또는 특정 텍스트(함수이름, 트레이서이름 등)을 입력해 트레이싱 준비를 한다.

이는 편하게 shell script로 만들어서 사용한다.

 

 

문단 단위로 설정을 분석 해보자.

 

먼저 트레이싱을 비활성화 합니다.

1초의 sleep은 쉘스크립트, 즉 비활성화 동작을 기다려 주는 것이다.

/sys/kernel/debug/tracing/tracing_on 이름만 봐도 어떤 파일인지 짐작이 간다.

(0 -> 비활성화, 1 -> 활성화)

 

/sys/kernel/debug/tracing/events/enable 를 비활성화한다.

이벤트는 아래에서 설명함

 

/sys/kernel/debug/tracing/events/set_ftrace_filter

더미 함수에대한 필터 활성화한다.

이 파일은 사용자가 어떤 함수를 트레이싱 할 지 함수 목록을 설정하는 파일임.

set_ftrace_filter는 설정하지 않았을 때 모든 함수가 저장되어 있다.

따라서 커널이 실행될때 한 번만 수행되는 secondary_start_kernel을 더미로 입력해야한다.

 

echo function > /sys/kernel/debug/tracing/current_tracer

트레이서의 종류 즉 트레이싱 결과를 어떤 형식으로 보여줄 것인지 설정.

echo function에서 function 외에 function_graph,nop 과 같은 옵션이 있다.

function_graph

 

예시로 function_graph 트레이서 로그를 보자.

0) -> 0번 CPU사용 중

+ -> 10us이상일때 (100us이상일땐 !)

43.556us -> sdio_writel(); 함수가 실행되는데 걸린 시간

50.222us -> brcmf_sdiod_writel [brcmfmac](); 함수가 실행되는데 걸린 시간

 

irq/36--79 => kworker-17102

-> 하이픈 왼쪽은 프로세스 이름, 하이픈 오른쪽의 숫자는 프로세스 번호

-> 0번CPU에서 irq/36--79프로세스를 실행시키다 kworker-17102프로세스로 스케줄링 하는 과정 같음..(정확x)

 

brcmf_sdiod_writel [brcmfmac]() 함수가 sdio_writel() 함수를 호출한 형태를 볼 수 있다.

 

 

echo vfs_open > /sys/kernel/debug/tracing/events/set_ftrace_filter 

심플하게 가장 중요한 부분이다.

트레이싱 하고싶은 함수를 설정하는 부분이다.

 

/sys/kernel/debug/tracing/events/sched/sched_wakeup/enable

/sys/kernel/debug/tracing/events/irq/irq_handler_entry/enable

 

sched

설정시 프로세스 스케줄링 동작과 스케줄링 프로파일링을 트레이싱 하는 이벤트를 볼 수 있다.

sched_wakeup : 프로세스 깨우는 동작

sched_switch : 컨텍스트 스위칭 동작

 

irq

설정시 인터럽트와 소프트웨어 인터럽트를 트레이싱 하는 이벤트를 볼 수 있다.

irq_handler_entry : 인터럽트가 발생한 시각과 인터럽트 번호 및 이름 출력

irq_handler_exit : 인터럽트 핸들링 완료

softirq_raise : Soft IRQ 서비스 실행 요청

softirq_entry : Soft IRQ 서비스 실행 시작

softirq_exit : Soft IRQ 서비스 실행 완료

 

/sys/kernel/debug/tracing/options/func_stack_trace

set_ftrace_filter를 통해 트레이싱하기로한 함수의 콜 스택을 출력하는 설정

 

/sys/kernel/debug/tracing/options/sym-offset

함수의 논리 주소와 물리 주소간의 오프셋을 알아내어

하드웨어(메모리?)에서 이름,인자,변수 등을 식별하여 더 정확한 정보 제공

 

/sys/kernel/debug/tracing/tracing_on

마지막으로 tracing을 활성화 시켜 동작하게 한다.

 

트레이서를 동작시키고,

이제 원하는 함수를 실행시켜 로그를 남긴후에

 

 

위 쉘스크립트 코드를 만들어

트레이싱 종료, 로그를 현재 디렉터리로 가져온다.

 

cat이나 vi로 ftrace_log.c 파일을 확인

 

참고 자료

https://www.kernel.org/doc/Documentation/trace/ftrace.rst

 

 

ctags

 

ctags란?

 

리눅스 환경에서 코드를 이해하기 위해 함수,변수,매크로 등 프로그래밍 언어적 요소를 인덱싱하여

'tags' 파일을 생성하며, 원하는 함수나 변수를 찾아 그 요소의 파일로 이동 및 원래 파일로 복귀를 도와주는 툴이다.

(apt-get과 같은 패키지 관리자를 이용해 설치해야함)

 

쉽게 말하면 작성한 코드들의 요소(변수,함수 등)을 따로 정리해두는 'tags' 파일을 생성하고,

요소(코드)의 위치로 이동 및 복귀를 돕는 툴이다. 

 

사용법

 

ctags -R *

기본적으로 위와 같은 형태로 사용하며 -R옵션은 recursive라는 의미이고,

이는 현재 위치에 있는 모든 파일과 디렉토리의 자식,손자..의 파일을 인덱싱하여 'tags'라는 파일을 만들라는 명령어 이다.

 

 

 

위 명령어를 사용하면 현재디렉토리에  tags라는 파일이 생성된다.

 

임의로 malloc이라는 함수를 찾아보자.

tags를 생성한 디렉토리에서 vi로 아무 파일을 열어보고, esc를 눌러 명령어 입력 모드로 전환한다.

 

Ctrl+]  함수가 정의된 파일로 이동
Ctrl+t  이동하기 전 단계의 위치로 이동
:ta ~~  키워드와 일치하는 태그위치 
:ts  <function-name> 같은 이름의 function-name이 여러개 일때, 목록을 보여준다. 번호를 이용해서 선택할 수 있다
:tn ~~  여러개의 함수이름이 존재할 때, 다음 함수를 선택한다.
:tp ~~  이전 함수를 선택한다.
:tfirst ~~  가장 처음에 찾았던 함수를 선택한다.
:tlast ~~  가장 마지막 함수를 선택한다.
:tags  이동했던 태그목록들 출력

 

:ts malloc

위 명령어를 입력한다.

 

위와같은 화면이 나오게 되는데 여기서 

# : 사용자가 선택하기 위한 임의의 리스트 인덱스

pri : F(Fully matched),C( in Current file), S(Static) 등의 의미 (아래 참조)

kind : f(function), v(variable), d(macro definition), t(typedef), s(structure), m or g(member of enum, struct, union) 등이있다.

보라색 글씨 : Tag이름 ex) malloc

파란색 글씨 : 요소가 위치한 파일경로 ex) lib/inflate.c

보라색 아래의 흰 글씨 : 요소가 작성된 line번호 or 요소의 표현식 (코드 부분)

tag priority (vi 에서&nbsp; ":help tag-priority" 명령어 사용)

 

7번 요소의 위치로 이동해 보자.

include/linux/zpool.h

 

해당 화면이 나오면 코드를 읽을 수 있게 되고 Ctrl + t입력하여 이동하기 전으로 돌아갈 수 있다.

 

 

cscope

 

cscope란?

 

ctags와 비슷하지만 조금 더 많은 내용을 추적할 수 있다.

예를 들어

어떤 함수를 호출한 함수

어떤 함수가 호출한 함수

찾고 싶은 문자열 

등 다양하게 확인해 볼 수 있다.

 

사용법

 

cscope -Rbq

 

-R : recursive(하위 디렉터리 까지 보겠다는 뜻)

-b : 데이터베이스 생성

-q : 검색 프롬프트 사용지정

 

 

검색하는 방법 -1

 

cscope -d

명령어 사용 하여 데이터베이스를 open

 

cscope -d

 

데이터 베이스에서 방향키 또는 enter(return)키로 검색 유형을 선택할 수 있으며 종료는 Ctrl + d 이다.

검색 유형에는 문자열 찾기, 함수 찾기, 심볼찾기, 호출한 함수 찾기 등등 이다.

단순히 문자열 찾는 것만으로도 ctags보다 넓고, 호출함수도 찾아주기에 더 깊다고 볼 수 있다.

 

? + enter를 통해  cscope 데이터 베이스 활용법에 대해 알 수 있다.

 

 

검색하는 방법 -2

 

vi 에서도 검색이 가능하다.

do_skip 함수가 call하는 함수를 찾아보는 예시로 포스팅을 마치겠다.

 

:cs find <options> keyword

위는 기본적인 명령어 형태이고, 아래 옵션을 통해 검색 유형을 선택할 수 있다.

 

0 (s) - 키워드를 검색
1 (g) - 선언 (정의) 되어 있는 부분으로 이동
2 (d) - 이 함수가 호출 하는 함수 목록 출력
3 (c) - 이 함수를 호출하는 함수 출력
4 (t) - 문자열 검색
5 (e) - 확장 정규식을 사용하여 검색
7 (f) - 파일 검색 (파일 이름 검색)
8 (i) - 이 파일을 include 하는 파일을 검색

 

 

함수를 호출하는 라인, 함수 호출 코드, 함수위치 등이 포함되어 있다.