Linux Kernel(4.19) Hacks

rousalome.egloos.com

포토로그 Kernel Crash


통계 위젯 (화이트)

102258
1323
114604


[리눅스커널] Crash: 비트 플립 @profile_tick() [Crash]Troubleshooting!!

이번에는 비트 플립으로 발생한 커널 패닉 코어 덤프 분석 과정을 소개합니다.

다음은 T32로 커널 패닉이 발생했을 때 잡은 콜스택입니다.
01 -000|machine_restart(?)
02 -001|arch_local_irq_enable(inline)
03 -001|panic(fmt = 0xC0EF195A)
04 -002|oops_end(inline)
05 -002|die(str = 0xC017409E, ?, err = -590234666)
06 -003|do_undefinstr(regs = 0xDCD1BCA8)
07 -004|__und_svc_fault(asm)
08  -->|exception
09 -005|profile_tick(type = -590234136)
10 -006|tick_sched_timer(timer = 0xC5B5B620)
11 -007|static_key_false(inline)
12 -007|trace_hrtimer_expire_exit(inline)
13 -007|__run_hrtimer(timer = 0xC5B5B620, now = 0xDCD1BD68)
14 -008|hrtimer_interrupt(?)
15 -009|timer_handler(inline)
16 -009|arch_timer_handler_virt(?, ?)
17 -010|static_key_false(inline)
18 -010|trace_irq_handler_exit(inline)
19 -010|handle_percpu_devid_irq(irq = 20, desc = 0xE1C08F00)
20 -011|generic_handle_irq(irq = 20)
21 -012|handle_IRQ(irq = 20, ?)
22 -013|gic_handle_irq(regs = 0xC5B5B620)
23 -014|__irq_svc(asm)
24  -->|exception
25 -015|open_check_o_direct(f = 0xDB621900)
26 -016|do_last(nd = 0xDCD1BF00, path = 0xDCD1BEC0, file = 0xDB621900, ?, opened = 0xDCD1BEBC, name = 0xC02057EC)
27 -017|path_openat(dfd = -100, ?, nd = 0xDCD1BF00, op = 0xDCD1BF78, flags = 65)  // /proc/32/status
28 -018|do_filp_open(dfd = -100, pathname = 0xD44BC000, op = 0xDCD1BF78, flags = 1)
29 -019|do_sys_open(dfd = -614328064, ?, flags = 131072, ?)

콜스택 정보로 보아 profile_tick() 함수에서 undefined instruction 익셉션이 발생했음을 알 수 있습니다.
07 -004|__und_svc_fault(asm)
08  -->|exception
09 -005|profile_tick(type = -590234136)
10 -006|tick_sched_timer(timer = 0xC5B5B620)

07번 째 줄을 보면 undefined instruction 익셉션 벡터인 __und_svc_fault 레이블을 볼 수 있습니다.

문제를 분석하기 위해 익셉션이 발생한 0xc0174084 주소 코드를 점검했습니다.
01 0xc0174084 <profile_handoff_task+0x24>:                 ; <UNDEFINED> instruction: 0x87bfd030
 /root/pi/kernel/kernel/profile.c: 154
02  0xc0174088 <profile_munmap>:    andeq   r0, r0, r0
 /root/pi/kernel/kernel/profile.c: 155
03 0xc017408c <profile_munmap+0x4>:        ldmdahi r7!, {r3, r4, r5, r6, r8, r12, sp, lr, pc}^

0xc0174084 주소에 있는 어셈블리 코드를 보니 <UNDEFINED> instruction:을 확인할 수 있습니다.

0xc0174084 주소에서 비트 플립으로 익셉션이 발생했음을 확인할 수 있었습니다.

덧글

  • 하루n 2019/01/28 18:35 # 삭제 답글

    안녕하십니까 오랜만에 덧글 남기게 되었습니다 다름이 아니라 실제로 코어 덤프는 어떻게 받으시는지 궁금합니다. 지금까지 장비가 없어서 T32 실습을 할 수 없어서 아쉬웠었습니다 그런데 그동안 T32 simulator에서 코어 덤프 파일을 분석 해오셨다는 걸 이제야 깨닫게 되어서 직접 따라해보려고 합니다. 그런데 퀼컴이나 MTK는 자체적으로 커널 패닉 시 코어덤프를 저장한다고 한다던데 현재 사용 중인 TI 쪽은 그런 솔루션이 없어 어떤 방법으로 하는게 좋을지 조언 부탁 드리고자 합니다.
  • AustinKim 2019/01/28 23:53 # 답글

    리눅스 시스템 개발자로써 고생이 많으십니다.

    혹시 커널 패닉이 발생했다면 커널 로그를 확보할 수 있나요?
    커널 패닉 로그와 vmlinux만 있어도 커널 패닉 시 콜스택을 T32 시뮬레이터로 복원할 수 있습니다.

    아래 메일로 커널 패닉 로그와 커널 패닉이 난 커널 이미지에 해당하는 vmlinux를 한번 보내주세요.
    austindh.kim@gmail.com

    보내주시면 Youtube 동영상으로 T32 디버깅 방법을 공유해드리겠습니다.
  • 하루n 2019/01/29 12:55 # 삭제 답글

    업무 보시느라 바쁘고 피곤하실텐데 답변 주셔서 감사드립니다!

    현재 커널 패닉 이슈가 발생한 것은 아니며
    단순히 공부차원에서 덤프 방법을 여쭤보게 되었습니다
    부끄럽지만 커널 덤프 받는 방법조차 모르는 상황입니다
    그리하여 kdump 를 통해 커널 덤프를 받아보려고 스터디 중입니다
    혹시 다른 방법이 있으면 알려주시면 감사하겠습니다

    그리고, 커널 패닉 로그와 vmlinux 만으로도 가능하다니 매우 흥미롭습니다

    혹시 T32 디버깅 관련 동영상을 볼 수 있게 된다면
    저뿐만 아니라 다른 분들도 정말 많은 도움이 될 것 같습니다
    염치불구하고 영상을 부탁 드리고자 합니다

    감사합니다
  • 하루n 2019/03/11 19:15 # 삭제 답글

    안녕하십니까
    적어도 kdump로 한번은 해보고 메일 드리자고 했던 것이 이렇게 시간이 지났습니다

    근황을 말씀드리면 타겟보드 상에서 kexec 통해 2차 커널로 부팅해서 vmcore 생성된 것을 받아서
    crash로 열어봤습니다만 warning 메세지가 뜨고 덤프가 잘 안됬는지 표시되는 정보가 불완전하더군요
    사용중인 크로스-툴체인의 gdb로는 별 에러 없이 덤프를 불러오던데 희안합니다

    커널 소스의 documentation 폴더에 있는 kdump.txt 과 여러 사이트 참고해서 진행했는데
    처음 해보는 것이라 어둠 속을 헤매는 기분이였습니다

    초기에는 kexec 프로그램에서 에러가 나고 잘 안되더군요
    "kexec_file_load syscall이 구현되어 있지 않다" "reserved memory를 못찾겠다"

    누가 이기나 한번 해보자 해서 kexec 어플리케이션과 커널에 디버거 걸어가면서 쭉 따라가 봤습니다

    처음 커널 cmdline에 crashkernel=X@Y 식으로 예약메모리 공간을 설정하게 되는데 kdump.txt에서는
    ARM은 시작주소 지정 안해도 된다라는 식으로 나와있어 크기만 지정하고 iomem을 보니 예약메모리 영역이
    0번지 근처에서 놀길래 가상주소 적용되서 괜찮은가 싶었지만 디버깅 시 예외처리되서 프로그램이 꺼져버리더군요
    그래서 512M 물리메모리영역 0x80000000-0x9fffffff 사이에 들어가도록 예약메모리 시작 번지를 지정했습니다.
    crashkernel=32M@2250M 이런 식으로요 그 후로는 reserved memory를 못찾겠다는 에러는 안나더군요

    그리고 옵션에 kexec_load 과 kexec_file_load 옵션이 있던데 kexec 어플리케이션 실행 시
    디폴트로 kexec_file_load 옵션으로 진행되고 x86에만 kexec_file_load 시스템콜이 포함 되더있더군요
    그래서 꾸역꾸역 arm linux 커널 수정해서 kexec_file_load 시스템 콜이 빌드되도록 수정했습니다.
    그러나 잘 안되어서 kexec_load 쪽으로 진행되도록 어플리케이션 수정해서 진행하다가
    커널 패닉이 2번이나 발생했다는 점에 뒤늦게 눈치 챘습니다

    echo c > /proc/sysrq-trigger 로 임의로 커널 패닉을 유발한거라 로그가 1번만 출력되야하는데 말이죠

    TI 는 kdump 관련해서 이슈가 있는 모양입니다 2번째 커널 패닉로그를 보니 omap_set_gpio_triggering에서
    유발된 듯 싶더군요 그래서 구글링해보니 관련 내용이 있어 패치 적용 후 진행이 되었습니다.

    https://patchwork.kernel.org/patch/8050131/ <---- 상기 이슈 관련 링크

    그래서 2차 커널로 부팅을 해야하는데 멈춰있는것 처럼 콘솔창에 아무것도 뜨지 않더군요
    아무래도 정상적인 부팅 절차는 아니니 분명 어디선가 문제가 있는 것이라 생각하여
    눈물을 머금고 2차 커널 초기화 부분도 계속 디버거로 따라가 봤습니다
    2차 커널은 기존 커널과 달리 다른 메모리 번지에서 돌아서 디버거에서 심볼을 못찾는다고 뜨더군요
    ccs stuido에서 소스코드는 물론이고 심볼정보도 안떠서 수동으로 디스어셈블리 해서 심볼보고
    현재 pc가 가리키는 주소에 저장된 명령어와 정확히 일치하는 오브젝트 파일의 행을 찾아서
    해당 오브젝트 파일의 소스파일 보며 서적과 사이트를 참고해서 어찌어찌 부팅과정을 따라갔습니다

    ARM Instruction 으로 부팅하는 과정은 경이롭더군요
    실제 page table 만드는 것도 이때 처음 봤습니다 (이론서에서만 이렇게 된다고만 알았지 실제로 봐보려고는 못했습니다)
    b start_kernel 전에 bp를 걸었는데 뻗더군요 그래서 찾았다 해서 다시 세밀하게 해봤는데 start_kernel 잘 들어가지더군요;
    이제는 step over로 빠르게 넘겨가다가 커널 부팅 후 cpu_idle 코드까지도 잘 가더군요
    어.. 뭐지 하고 디버거 푸는 순간 콘솔에 쫘아아악 부팅 로고가 뜨고 로그인 커서가 깜빡이고 있더군요
    그렇게 /proc/vmcore 생성을 확인했습니다 (이걸 빼내는데 또 고생을 했지만 scp 써서 뺐습니다)

    그 동안의 과정을 통해 여러모로 공부가 됬습니다

    감사합니다
  • AustinKim 2019/03/12 07:04 #

    엄청난 고생 끝에 결실을 맺으셔서 다행입니다.

    혹시 가능하면 /proc/vmcore 에 만들어진 vmcore(vmcore에 매핑하는 vmlinux)를 보내주실 수 있으신가요?
    이메일: austindh.kim@gmail.com

    크래시 유틸리티로 vmcore를 올린 후 T32 시뮬레이터에서 로딩할 수 있는 포멧으로 덤프를 추출할 수 있습니다. 이 방법 공유드리겠습니다.

    그리고 제가 새로운 책을 기획 중인데요. 크래시 유틸리티로 커널 디버깅을 하면서 리눅스 커널을 설명하는 컨셉입니다. 독자들이 크래시 유틸리티로를 실습하면서 리눅스 커널 자료 구조를 공부할 수 있게 하려는 것이죠. 그래서 다양한 vmcore를 모으고 있습니다.
    (올려주신 답글을 보니 x86 아키텍처에서 개발하시는 것 같습니다.)

    PS: 혹시 vmlinux나 vmcore에 현재 몸담고 있는 개발실에서 적용한 유용한 드라이버 코드가 있으면 공유 안해 주셔도 됩니다. ^^
  • 하루n 2019/03/12 23:56 # 삭제 답글

    코어 덤프 관련하여 메일 보내드렸습니다

    오늘 아침에 답변주신 내용을 보고선 좀 더 노력해보니 거의 완전한 덤프파일을 얻을 수 있었습니다

    일단 crashkernel 예약 메모리 공간이 128M 이상일때 잘 진행되는 것을 확인하였습니다
    당시 2차 커널 초기화 과정 디버깅 시 256M로 잡고 해서 정상적으로 진행되었던 것이였습니다

    그리고 scp로 vmcore 파일을 빼내려고 할 때, 커널 패닉이 발생하는데
    vmcore 관련 kernel 패치를 적용하여 온전하게 빼낼 수 있었습니다

    우여곡절 끝에 해당 덤프파일을 crash로 열어봐서 써보니 정말 신세계더군요
    여기에 T32 까지 쓴다면 천군만마를 얻을 것만 같습니다

    다만, runq 가 잘 동작하지 않습니다
    runq: per-cpu runqueues do not exist 라는 에러만 뜨더군요
    crash tool쪽 소스코드를 봐보니 per-cpu 관련 심볼을 찾아오려고 하는데 실패하면 뜨는 에러인 것 같습니다
    현재 타겟보드 SoC가 싱글코어라 커널 SMP 기능은 disable 되어 있습니다
    vmlinux.lds 에서도 per-cpu 관련 섹션이 없더군요

    확신은 없어서 멀티코어 보드에서도 테스트 해보려고 준비 중입니다

    감사합니다
  • 하루n 2019/03/13 09:09 # 삭제 답글

    참고로, vmcore 복사 시 발생하는 커널패닉 관련 패치 링크입니다
    http://lists.infradead.org/pipermail/linux-arm-kernel/2014-April/249908.html

  • AustinKim 2019/03/13 15:43 #

    여러가지 유익한 정보 감사합니다.

    CONFIG_SMP 컨피그가 꺼져 있으면 런큐 runqueues 변수가 컴파일되지 않습니다.
    그래서 크래시 유틸리티에서 런큐를 제대로 덤프하지 못하는 것 같습니다.

    보내주신 vmcore 감사합니다. vmcore는 올려본 다음 메일 드리겠습니다.
댓글 입력 영역