[crash-utility] kvm(Arm64) vmcore 로딩 + ftrace 추출

vmcore 실행

 

아래와 같은 커맨드를 셸 스크립트로 저장한 다음에 last_run_arm64.sh으로 저장합니다.

 

#!/bin/sh

export CRASH_EXTENSIONS=/home001/austindh.kim/crashtool/crash/extensions

export TRACE_CMD=/home001/austindh.kim/bin/CrashTool/trace-cmd

 

~/ramdumps/99_crash/crash/crash dump.202203252027 vmlinux-5.4.0-105-generic

 

last_run_arm64.sh 셸 스크립트를 실행합니다.

 

(base) austindh.kim:~/ramdumps/kvm_aarch64_coredump$ ./last_run_arm64.sh

 

crash 8.0.0++

Copyright (C) 2002-2021  Red Hat, Inc.

Copyright (C) 2004, 2005, 2006, 2010  IBM Corporation

 

 

crash 8.0.0++

Copyright (C) 2002-2021  Red Hat, Inc.

Copyright (C) 2004, 2005, 2006, 2010  IBM Corporation

Copyright (C) 1999-2006  Hewlett-Packard Co

Copyright (C) 2005, 2006, 2011, 2012  Fujitsu Limited

Copyright (C) 2006, 2007  VA Linux Systems Japan K.K.

Copyright (C) 2005, 2011, 2020-2021  NEC Corporation

Copyright (C) 1999, 2002, 2007  Silicon Graphics, Inc.

Copyright (C) 1999, 2000, 2001, 2002  Mission Critical Linux, Inc.

Copyright (C) 2015, 2021  VMware, Inc.

This program is free software, covered by the GNU General Public License,

and you are welcome to change it and/or distribute copies of it under

certain conditions.  Enter "help copying" to see the conditions.

This program has absolutely no warranty.  Enter "help warranty" for details.

 

GNU gdb (GDB) 10.2

Copyright (C) 2021 Free Software Foundation, Inc.

License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>

This is free software: you are free to change and redistribute it.

There is NO WARRANTY, to the extent permitted by law.

Type "show copying" and "show warranty" for details.

This GDB was configured as "--host=x86_64-pc-linux-gnu --target=aarch64-elf-linux".

Type "show configuration" for configuration details.

Find the GDB manual and other documentation resources online at:

    <http://www.gnu.org/software/gdb/documentation/>.

 

For help, type "help".

Type "apropos word" to search for commands related to "word"...

 

      KERNEL: vmlinux-5.4.0-105-generic

    DUMPFILE: dump.202203252027  [PARTIAL DUMP]

        CPUS: 2

        DATE: Sat Mar 26 05:26:00 KST 2022

      UPTIME: 00:02:36

LOAD AVERAGE: 0.45, 0.48, 0.20

       TASKS: 150

    NODENAME: kim

     RELEASE: 5.4.0-105-generic

     VERSION: #119-Ubuntu SMP Mon Mar 7 18:50:13 UTC 2022

     MACHINE: aarch64  (unknown Mhz)

      MEMORY: 2 GB

       PANIC: "Kernel panic - not syncing: sysrq triggered crash"

         PID: 1098

     COMMAND: "bash"

        TASK: ffff195a20b5bc00  [THREAD_INFO: ffff195a20b5bc00]

         CPU: 0

       STATE: TASK_RUNNING (PANIC)

 

시스템 정보 확인하기

 

잘 로딩되네요. 이번에 mach 명령어를 입력해 커널과 관련된 메모리 설정을 확인하겠습니다.

 

crash> mach

       MACHINE TYPE: aarch64

        MEMORY SIZE: 2 GB

               CPUS: 2

                 HZ: 250

          PAGE SIZE: 4096

KERNEL VIRTUAL BASE: ffff000000000000

KERNEL MODULES BASE: ffff800008000000

KERNEL VMALLOC BASE: ffff800010000000

KERNEL VMEMMAP BASE: fffffdffffe00000

  KERNEL STACK SIZE: 16384

     IRQ STACK SIZE: 16384

         IRQ STACKS:

              CPU 0: ffff800010000000

              CPU 1: ffff800010008000

OVERFLOW STACK SIZE: 4096

    OVERFLOW STACKS:

              CPU 0: ffff195a3fbb42a0

              CPU 1: ffff195a3fbd52a0

 

이번에는 sys 명령어를 입력해 시스템 정보를 확인합니다.   

  

crash> sys

      KERNEL: vmlinux-5.4.0-105-generic

    DUMPFILE: dump.202203252027  [PARTIAL DUMP]

        CPUS: 2

        DATE: Sat Mar 26 05:26:00 KST 2022

      UPTIME: 00:02:36

LOAD AVERAGE: 0.45, 0.48, 0.20

       TASKS: 150

    NODENAME: kim

     RELEASE: 5.4.0-105-generic

     VERSION: #119-Ubuntu SMP Mon Mar 7 18:50:13 UTC 2022

     MACHINE: aarch64  (unknown Mhz)

      MEMORY: 2 GB

       PANIC: "Kernel panic - not syncing: sysrq triggered crash"

   

런큐를 확인하니 CPU 코어의 갯수는 2개이네요.    

   

crash> runq

CPU 0 RUNQUEUE: ffff195a3fbc9e40

  CURRENT: PID: 1098   TASK: ffff195a20b5bc00  COMMAND: "bash"

  RT PRIO_ARRAY: ffff195a3fbca100

     [no tasks queued]

  CFS RB_ROOT: ffff195a3fbc9f78

     [no tasks queued]

 

CPU 1 RUNQUEUE: ffff195a3fbeae40

  CURRENT: PID: 0      TASK: ffff195a3c129e00  COMMAND: "swapper/1"

  RT PRIO_ARRAY: ffff195a3fbeb100

     [no tasks queued]

  CFS RB_ROOT: ffff195a3fbeaf78

     [no tasks queued]

crash>

 

crash> log -m

[    0.000000] <2>Booting Linux on physical CPU 0x0000000000 [0x410fd083]

[    0.000000] <2>Linux version 5.4.0-105-generic (buildd@bos02-arm64-047) (gcc version 9.4.0 (Ubuntu 9.4.0-1ubuntu1~20.04)) #119-Ubuntu SMP Mon Mar 7 18:50:13 UTC 2022 (Ubuntu 5.4.0-105.119-generic 5.4.174)

[    0.000000] <2>efi: Getting EFI parameters from FDT:

[    0.000000] <2>efi: EFI v2.70 by EDK II

[    0.000000] <2>efi:  SMBIOS 3.0=0xbbef0000  MEMATTR=0xba43d018  ACPI 2.0=0xb8520000  MOKvar=0xba444000  RNG=0xbbffca98  MEMRESERVE=0xb850d718

[    0.000000] <2>efi: seeding entropy pool

[    0.000000] <2>random: fast init done

...

[   27.130013] <2>audit: type=1400 audit(1648239831.635:11): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/usr/lib/NetworkManager/nm-dhcp-client.action" pid=590 comm="apparmor_parser"

[   42.101160] <2>fbcon: Taking over console

[  157.573606] <2>sysrq: Trigger a crash

[  157.579851] <2>Kernel panic - not syncing: sysrq triggered crash

[  157.587393] <2>CPU: 0 PID: 1098 Comm: bash Kdump: loaded Not tainted 5.4.0-105-generic #119-Ubuntu

[  157.598299] <2>Hardware name: QEMU KVM Virtual Machine, BIOS 0.0.0 02/06/2015

[  157.607011] <2>Call trace:

[  157.610187] <2> dump_backtrace+0x0/0x190

[  157.614918] <2> show_stack+0x28/0x38

[  157.619169] <2> dump_stack+0xb4/0x10c

[  157.623689] <2> panic+0x150/0x364

[  157.627649] <2> sysrq_handle_reboot+0x0/0x30

[  157.632842] <2> __handle_sysrq+0x90/0x180

[  157.637666] <2> write_sysrq_trigger+0x138/0x178

[  157.643105] <2> proc_reg_write+0x90/0xe0

[  157.647864] <2> __vfs_write+0x4c/0x90

[  157.652416] <2> vfs_write+0xe8/0x1c8

[  157.657366] <2> ksys_write+0x7c/0x108

[  157.661709] <2> __arm64_sys_write+0x28/0x38

 

vmcore에서 ftrace 추출하기

 

이번에는 vmcore에서 ftrace를 추출하겠습니다. 

 

extend 명령어와 '/home001/austindh.kim/crashtool/crash/extensions/trace.so' 경로를 지정합니다.

 

crash> extend /home001/austindh.kim/crashtool/crash/extensions/trace.so

/home001/austindh.kim/crashtool/crash/extensions/trace.so: shared object loaded

 

'trace show' 명령어를 실행해 vmcore에서 ftrace 메시지를 추출합니다. 

 

crash> trace show

...

 

cpus=2

           <...>-1090  [001]   137.918598: sched_wakeup:         comm=bash pid=1057 prio=120 target_cpu=000

           <...>-1090  [001]   137.918646: sched_switch:         prev_comm=bash prev_pid=1090 prev_prio=120 prev_state=Z ==> next_comm=swapper/1 next_pid=0 next_prio=120

          <idle>-0     [000]   137.918696: sched_switch:         prev_comm=swapper/0 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=bash next_pid=1057 next_prio=120

            bash-1057  [000]   137.919187: irq_handler_entry:    irq=2 name=arch_timer

            bash-1057  [000]   137.919217: softirq_raise:        vec=1 [action=TIMER]

            bash-1057  [000]   137.919229: softirq_raise:        vec=7 [action=SCHED]

          <idle>-0     [001]   137.919241: irq_handler_entry:    irq=2 name=arch_timer

            bash-1057  [000]   137.919243: irq_handler_exit:     irq=2 ret=handled

...

          <idle>-0     [001]   157.675082: softirq_raise:        vec=1 [action=TIMER]

          <idle>-0     [001]   157.675092: softirq_raise:        vec=7 [action=SCHED]

          <idle>-0     [001]   157.675155: sched_wakeup:         comm=irqbalance pid=647 prio=120 target_cpu=001

          <idle>-0     [001]   157.675162: irq_handler_exit:     irq=2 ret=handled

          <idle>-0     [001]   157.675165: softirq_entry:        vec=1 [action=TIMER]

          <idle>-0     [001]   157.675181: sched_wakeup:         comm=rcu_sched pid=10 prio=120 target_cpu=001

          <idle>-0     [001]   157.675185: softirq_exit:         vec=1 [action=TIMER]

          <idle>-0     [001]   157.675186: softirq_entry:        vec=7 [action=SCHED]

          <idle>-0     [001]   157.675208: softirq_exit:         vec=7 [action=SCHED]

          <idle>-0     [001]   157.675234: sched_switch:         prev_comm=swapper/1 prev_pid=0 prev_prio=120          prev_state=R ==> next_comm=irqbalance next_pid=647 next_prio=120

      irqbalance-647   [001]   157.677484: sched_switch:         prev_comm=irqbalance prev_pid=647 prev_prio=120       prev_state=S ==> next_comm=rcu_sched next_pid=10 next_prio=120

       rcu_sched-10    [001]   157.677579: sched_switch:         prev_comm=rcu_sched prev_pid=10 prev_prio=120         prev_state=I ==> next_comm=swapper/1 next_pid=0 next_prio=120

          <idle>-0     [001]   157.679116: irq_handler_entry:    irq=2 name=arch_timer

          <idle>-0     [001]   157.679239: irq_handler_exit:     irq=2 ret=handled

          <idle>-0     [001]   157.683337: irq_handler_entry:    irq=2 name=arch_timer

          <idle>-0     [001]   157.683497: irq_handler_exit:     irq=2 ret=handled

          <idle>-0     [001]   157.687195: irq_handler_entry:    irq=2 name=arch_timer

          <idle>-0     [001]   157.687279: irq_handler_exit:     irq=2 ret=handled

 

sched_switch와 irq 관련 이벤트를 활성화했군요.