Overview
많은 개발자들은 '브링업'이란 개발 업무를 맡고 있습니다. 이 과정에서 다음과 같은 어려움을 많이 겪습니다.
* 보드 브링업을 하다 보니 컴퓨터의 시작 화면까지 보이지 않는다.
* 부팅 과정에서 출력하는 화면이 계속 출력된다.
이런 이슈를 겪은 적이 있나요? 보통 이런 상황을 겪으면 굉장히 답답하고 짜증이 납니다. 그 이유는 무엇일까요?
* 뭔가 문제가 생겨서 부팅이 안되는 상황인데 그 원인을 파악하기 어렵기 때문입니다.
달리 말씀을 드리면 정확히 어디에 문제가 생겨서 부팅이 안되는지 알 수 없기 때문입니다. 이번 포스팅에서는 이런 상황에서 사용하면 아주 유용한 커널 패치를 소개합니다.
아이디어
안드로이드나 라즈비안 타겟 부팅 과정에서 init이나 systemd 프로세스가 *.rc나 *.sh 셸 스크립트를 실행하면서 각종 서비스나 프로세스를 초기화합니다. 하지만 리눅스 커널 입장에서는 위 레이어에 안드로이드나 라즈비안 혹은 우분투가 돌아가는지 모릅니다. 이를 다음과 같이 요약해 볼까요?
"유저 공간에서 프로세스나 스레드 생성 요청이 오면 이를 생성한다."
"'실행 파일'을 실행할 때 커널은 말 그대로 실행시켜준다."
만약 안드로이드에서 각종 서비스를 실행할 때 커널은 이를 어떻게 처리할까요?
* /system/bin/sh 파일 처럼 실행할 뿐입니다.
커널 패치
서론이 길었는데, 먼저 커널 패치 코드를 소개합니다.
diff --git a/fs/exec.c b/fs/exec.c
index 77c03ce..49b51ce 100644
--- a/fs/exec.c
+++ b/fs/exec.c
@@ -1681,6 +1681,37 @@ int search_binary_handler(struct linux_binprm *bprm)
}
EXPORT_SYMBOL(search_binary_handler);
+
+#define PROCESS_ARG_BUFF_SIZE 128
+
+void get_process_exec_profile(const char *fname)
+{
+ char process_arg_buf[PROCESS_ARG_BUFF_SIZE] = {0,};
+ int len = 0;
+
+ len = get_cmdline(current, process_arg_buf, PROCESS_ARG_BUFF_SIZE -1);
+
+ if(len == 0) {
+ pr_info("[-] Error: len: %d \n", len);
+ return;
+ }
+
+ if(!fname) {
+ pr_info("[-] Error: fname null \n");
+ return;
+ }
+
+ if (len > PROCESS_ARG_BUFF_SIZE)
+ len = PROCESS_ARG_BUFF_SIZE;
+
+ process_arg_buf[len] = '\0';
+
+ pr_info("[exec:%s-%d] exec_file: %s, arg: [%s] \n",
+ current->comm, current->pid, fname, process_arg_buf);
+}
+#endif
+
+
static int exec_binprm(struct linux_binprm *bprm)
{
pid_t old_pid, old_vpid;
@@ -1698,6 +1729,9 @@ static int exec_binprm(struct linux_binprm *bprm)
trace_sched_process_exec(current, old_pid, bprm);
ptrace_event(PTRACE_EVENT_EXEC, old_vpid);
proc_exec_connector(current);
+
+ get_process_exec_profile(bprm->filename);
+
}
return ret;
패치 코드의 내용은 실행 파일과 실행 파일에 적용되는 아규먼트 옵션을 커널 로그로 출력해주는 것입니다.
커널 로그 확인
커밋을 반영하고 커널 로그를 받아보면 아래와 같은 시그니처를 볼 수 있습니다. 참고로 아래 로그는 안드로이드 디바이스에서 받았습니다.
2735:[ 77.839144 / 01-01 06:09:53.099][6] [exec:init-1] exec_file: /init, arg: [/init]
2748:[ 78.472964 / 01-01 06:09:53.739][7] [exec:init-1] exec_file: /system/bin/init, arg: [/system/bin/init]
2761:[ 78.957614 / 01-01 06:09:54.229][7] [exec:init-1] exec_file: /system/bin/init, arg: [/system/bin/init]
2776:[ 79.170175 / 01-01 06:09:54.429][1] [exec:init-542] exec_file: /system/bin/init, arg: [/system/bin/init]
2777:[ 79.172863 / 01-01 06:09:54.439][3] [exec:init-543] exec_file: /system/bin/init, arg: [/system/bin/init]
2780:[ 79.298571 / 01-01 06:09:54.559][1] [exec:ueventd-544] exec_file: /system/bin/ueventd, arg: [/system/bin/ueventd]
2781:[ 79.317985 / 01-01 06:09:54.579][0] [exec:apexd-545] exec_file: /system/bin/apexd, arg: [/system/bin/apexd]
2804:[ 79.584330 / 01-01 06:09:54.849][1] [exec:modprobe-546] exec_file: /vendor/bin/modprobe, arg: [/vendor/bin/modprobe]
2828:[ 80.124861 / 01-01 06:09:55.389][2] [exec:modprobe-555] exec_file: /vendor/bin/modprobe, arg: [/vendor/bin/modprobe]
3518:[ 385.662491 / 01-01 06:15:00.929][5] [exec:servicemanager-562] exec_file: /system/bin/servicemanager, arg: [/system/bin/servicemanager]
3519:[ 385.675577 / 01-01 06:15:00.939][6] [exec:logd-560] exec_file: /system/bin/logd, arg: [/system/bin/logd]
3520:[ 385.675634 / 01-01 06:15:00.939][7] [exec:hwservicemanage-563] exec_file: /system/bin/hwservicemanager, arg: [/system/bin/hwservicemanager]
3522:[ 385.711358 / 01-01 06:15:00.979][5] [exec:vndservicemanag-564] exec_file: /vendor/bin/vndservicemanager, arg: [/vendor/bin/vndservicemanager]
3524:[ 385.763532 / 01-01 06:15:01.029][6] [exec:android.hardwar-567] exec_file: /vendor/bin/hw/android.hardware.keymaster@4.0-service-qti, arg: [/vendor/bin/hw/android.hardware.keymaster@4.0-service-qti]
3525:[ 385.764325 / 01-01 06:15:01.029][4] [exec:android.hardwar-569] exec_file: /vendor/bin/hw/android.hardware.keymaster@4.0-strongbox-service-qti, arg: [/vendor/bin/hw/android.hardware.keymaster@4.0-strongbo
x-service-qti]
3527:[ 385.843622 / 01-01 06:15:01.109][6] [exec:vold-574] exec_file: /system/bin/vold, arg: [/system/bin/vold]
3532:[ 385.929238 / 01-01 06:15:01.189][4] [exec:e2fsck-589] exec_file: /system/bin/e2fsck, arg: [/system/bin/e2fsck]
3547:[ 386.199287 / 01-01 06:15:01.459][6] [exec:vdc-597] exec_file: /system/bin/vdc, arg: [/system/bin/vdc]
3557:[ 386.342132 / 01-01 06:15:01.609][6] [exec:recovery-refres-598] exec_file: /system/bin/recovery-refresh, arg: [/system/bin/recovery-refresh]
3559:[ 386.364102 / 01-01 06:15:01.629][4] [exec:spdaemon-599] exec_file: /vendor/bin/spdaemon, arg: [/vendor/bin/spdaemon]
3560:[ 386.375250 / 01-01 06:15:01.639][4] [exec:sec_nvm-600] exec_file: /vendor/bin/sec_nvm, arg: [/vendor/bin/sec_nvm]
3563:[ 386.412097 / 01-01 06:15:01.679][7] [exec:ipacm-diag-601] exec_file: /system/vendor/bin/ipacm-diag, arg: [/system/vendor/bin/ipacm-diag]
3565:[ 386.414373 / 01-01 06:15:01.679][5] [exec:android.hardwar-603] exec_file: /vendor/bin/hw/android.hardware.atrace@1.0-service, arg: [/vendor/bin/hw/android.hardware.atrace@1.0-service]
3566:[ 386.418336 / 01-01 06:15:01.679][5] [exec:ipacm-602] exec_file: /system/vendor/bin/ipacm, arg: [/system/vendor/bin/ipacm]
3567:[ 386.436995 / 01-01 06:15:01.699][1] [exec:android.hardwar-604] exec_file: /vendor/bin/hw/android.hardware.boot@1.0-service, arg: [/vendor/bin/hw/android.hardware.boot@1.0-service]
3568:[ 386.443772 / 01-01 06:15:01.709][5] [exec:wait_for_keymas-607] exec_file: /system/bin/wait_for_keymaster, arg: [/system/bin/wait_for_keymaster]
그렇다면 위 로그를 어떻게 해석할까요? 한 가지 예를 들겠습니다.
[ 385.662491 / 01-01 06:15:00.929][5] [exec:servicemanager-562] exec_file: /system/bin/servicemanager, arg: [/system/bin/servicemanager]
서비스 매니저가 실행됐다는 정보입니다. arg는 파일을 실행할 때의 아규먼트입니다.
이번에 다른 로그를 봅시다.
[ 400.060155 / 01-01 06:15:14.839][4] [exec:init.rpi_device.crash-1144] exec_file: /vendor/bin/init.rpi_device.crashdata.sh, arg: [/vendor/bin/sh]
'/vendor/bin/init.rpi_device.crashdata.sh' 셸 스크립트를 init.rpi_device.crash.sh 스크립트가 실행합니다.
부팅하고 난 다음에 다음 시그니처도 확인할 수 있습니다.
[ 442.944003 / 07-30 05:19:25.069][3] [exec:crash_dump64-4141] exec_file: /system/bin/crash_dump64, arg: [crash_dump64]
유저 공간에서 Tombstone이 떨어졌다는 사실을 알 수 있습니다.
다음은 가장 흥미로운 로그입니다.
[ 450.178083 / 07-30 05:19:32.299][2] [exec:sh-4946] exec_file: /system/bin/sh, arg: [/system/bin/sh]
[ 450.224563 / 07-30 05:19:32.349][7] [exec:dmesg-4946] exec_file: /system/bin/dmesg, arg: [dmesg]
위 로그는 다음 명령어를 실행했다는 사실을 알려줍니다.
adb shell dmesg > kernel_log.c
결론
이 패치를 적용하면 커널 로그를 통해 임베디드 리눅스의 어떤 배포판(안드로이드, 라즈비안)이던 부팅 과정을 확인할 수 있습니다. 리눅스 시스템 개발자들이여, 비슷한 문제를 겪으면 이 패치을 적용해 조금 더 일찍 퇴근합시다.
패치 설명 동영상
