[리눅스커널] 안드로이드/라즈베리 파이 부팅 실패 100% 해결하는 디버깅 패치

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

 

결론

 

이 패치를 적용하면 커널 로그를 통해 임베디드 리눅스의 어떤 배포판(안드로이드, 라즈비안)이던 부팅 과정을 확인할 수 있습니다. 리눅스 시스템 개발자들이여, 비슷한 문제를 겪으면 이 패치을 적용해 조금 더 일찍 퇴근합시다. 

 

패치 설명 동영상