Kernel의 printk의 Message이며 이 부분을 좀 다양하게 알아보자
1.1 dmesg (/dev/kmsg , /proc/kmsg)
Linux에서 Kernel Message를 보는 방법은 dmesg이며 각각의 Log Level을 아래의 사이트는 각각의 나타내고 있다.
- dmesg 기본사용법
- dmesg -c : dmesg clear dmeg도 내부에 buffer가 있기에 이를 전부 clear한다.
- dmesg -n1 : level 1 선택
- dmesg : 기본 설정값으로 하고 전부 출력.
- raspberry pi test
$ dmesg
[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.14.34-v7+ (dc4@dc4-XPS13-9333) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1110 SMP Mon Apr 16 15:18:51 BST 2018
[ 0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
[ 0.000000] CPU: div instructions available: patching division code
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[ 0.000000] OF: fdt: Machine model: Raspberry Pi 3 Model B Rev 1.2
[ 0.000000] Memory policy: Data cache writealloc
[ 0.000000] cma: Reserved 8 MiB at 0x37800000
[ 0.000000] On node 0 totalpages: 229376
[ 0.000000] free_area_init_node: node 0, pgdat 80c84e40, node_mem_map b7016000
[ 0.000000] Normal zone: 2016 pages used for memmap
[ 0.000000] Normal zone: 0 pages reserved
[ 0.000000] Normal zone: 229376 pages, LIFO batch:31
[ 0.000000] random: fast init done
[ 0.000000] percpu: Embedded 17 pages/cpu @b6fbf000 s38720 r8192 d22720 u69632
[ 0.000000] pcpu-alloc: s38720 r8192 d22720 u69632 alloc=17*4096
[ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 227360
[ 0.000000] Kernel command line: 8250.nr_uarts=0 bcm2708_fb.fbwidth=1920 bcm2708_fb.fbheight=1080 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=PARTUUID=0c830106-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles
[ 0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Memory: 887456K/917504K available (7168K kernel code, 575K rwdata, 2072K rodata, 1024K init, 706K bss, 21856K reserved, 8192K cma-reserved)
[ 0.000000] Virtual kernel memory layout:
vector : 0xffff0000 - 0xffff1000 ( 4 kB)
fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
vmalloc : 0xb8800000 - 0xff800000 (1136 MB)
lowmem : 0x80000000 - 0xb8000000 ( 896 MB)
modules : 0x7f000000 - 0x80000000 ( 16 MB)
.text : 0x80008000 - 0x80800000 (8160 kB)
.init : 0x80b00000 - 0x80c00000 (1024 kB)
.data : 0x80c00000 - 0x80c8fd4c ( 576 kB)
.bss : 0x80c96f4c - 0x80d478b4 ( 707 kB)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] ftrace: allocating 25231 entries in 74 pages
[ 0.000000] Hierarchical RCU implementation.
[ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[ 0.000000] arch_timer: cp15 timer(s) running at 19.20MHz (phys).
[ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[ 0.000007] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[ 0.000019] Switching to timer-based delay loop, resolution 52ns
[ 0.000267] Console: colour dummy device 80x30
[ 0.000285] console [tty1] enabled
[ 0.000311] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[ 0.000326] pid_max: default: 32768 minimum: 301
[ 0.000638] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.000654] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.001587] Disabling memory control group subsystem
[ 0.001668] CPU: Testing write buffer coherency: ok
[ 0.002063] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[ 0.002436] Setting up static identity map for 0x100000 - 0x10003c
[ 0.002553] Hierarchical SRCU implementation.
[ 0.003187] smp: Bringing up secondary CPUs ...
[ 0.003869] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[ 0.004620] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[ 0.005351] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[ 0.005455] smp: Brought up 1 node, 4 CPUs
[ 0.005465] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[ 0.005471] CPU: All CPU(s) started in HYP mode.
[ 0.005475] CPU: Virtualization extensions available.
[ 0.006318] devtmpfs: initialized
[ 0.016951] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4
[ 0.017172] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.017190] futex hash table entries: 1024 (order: 4, 65536 bytes)
[ 0.017747] pinctrl core: initialized pinctrl subsystem
[ 0.018489] NET: Registered protocol family 16
[ 0.021208] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[ 0.026004] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[ 0.026011] hw-breakpoint: maximum watchpoint size is 8 bytes.
[ 0.026219] Serial: AMBA PL011 UART driver
[ 0.027833] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[ 0.028291] uart-pl011 3f201000.serial: could not find pctldev for node /soc/gpio@7e200000/uart0_pins, deferring probe
[ 0.059373] bcm2835-dma 3f007000.dma: DMA legacy API manager at b8813000, dmachans=0x1
[ 0.060896] SCSI subsystem initialized
[ 0.061116] usbcore: registered new interface driver usbfs
[ 0.061167] usbcore: registered new interface driver hub
[ 0.061250] usbcore: registered new device driver usb
[ 0.070084] raspberrypi-firmware soc:firmware: Attached to firmware from 2018-04-16 18:21
[ 0.071479] clocksource: Switched to clocksource arch_sys_counter
[ 0.148866] VFS: Disk quotas dquot_6.6.0
[ 0.148951] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 0.149138] FS-Cache: Loaded
[ 0.149336] CacheFiles: Loaded
[ 0.158147] NET: Registered protocol family 2
[ 0.158869] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[ 0.158979] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[ 0.159165] TCP: Hash tables configured (established 8192 bind 8192)
[ 0.159294] UDP hash table entries: 512 (order: 2, 16384 bytes)
[ 0.159337] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[ 0.159565] NET: Registered protocol family 1
[ 0.160010] RPC: Registered named UNIX socket transport module.
[ 0.160015] RPC: Registered udp transport module.
[ 0.160021] RPC: Registered tcp transport module.
[ 0.160026] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.161604] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
[ 0.164342] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[ 0.172261] FS-Cache: Netfs 'nfs' registered for caching
[ 0.172848] NFS: Registering the id_resolver key type
[ 0.172878] Key type id_resolver registered
[ 0.172884] Key type id_legacy registered
[ 0.172899] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 0.174757] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[ 0.174878] io scheduler noop registered
[ 0.174884] io scheduler deadline registered (default)
[ 0.175161] io scheduler cfq registered
[ 0.175168] io scheduler mq-deadline registered
[ 0.175174] io scheduler kyber registered
[ 0.177839] BCM2708FB: allocated DMA memory f7910000
[ 0.177867] BCM2708FB: allocated DMA channel 0 @ b8813000
[ 0.235976] Console: switching to colour frame buffer device 240x67
[ 0.270983] bcm2835-rng 3f104000.rng: hwrng registered
[ 0.271111] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[ 0.271631] vc-sm: Videocore shared memory driver
[ 0.271898] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
[ 0.281547] brd: module loaded
[ 0.290519] loop: module loaded
[ 0.290532] Loading iSCSI transport class v2.0-870.
[ 0.291204] libphy: Fixed MDIO Bus: probed
[ 0.291299] usbcore: registered new interface driver lan78xx
[ 0.291355] usbcore: registered new interface driver smsc95xx
[ 0.291373] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 0.519585] Core Release: 2.80a
[ 0.519594] Setting default values for core params
[ 0.519629] Finished setting default values for core params
[ 0.719887] Using Buffer DMA mode
[ 0.719893] Periodic Transfer Interrupt Enhancement - disabled
[ 0.719898] Multiprocessor Interrupt Enhancement - disabled
[ 0.719905] OTG VER PARAM: 0, OTG VER FLAG: 0
[ 0.719914] Dedicated Tx FIFOs mode
[ 0.720246] WARN::dwc_otg_hcd_init:1046: FIQ DMA bounce buffers: virt = 0xb7904000 dma = 0xf7904000 len=9024
[ 0.720270] FIQ FSM acceleration enabled for :
Non-periodic Split Transactions
Periodic Split Transactions
High-Speed Isochronous Endpoints
Interrupt/Control Split Transaction hack enabled
[ 0.720277] dwc_otg: Microframe scheduler enabled
[ 0.720329] WARN::hcd_init_fiq:459: FIQ on core 1 at 0x805e6a40
[ 0.720340] WARN::hcd_init_fiq:460: FIQ ASM at 0x805e6da8 length 36
[ 0.720352] WARN::hcd_init_fiq:486: MPHI regs_base at 0xb887e000
[ 0.720408] dwc_otg 3f980000.usb: DWC OTG Controller
[ 0.720440] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[ 0.720470] dwc_otg 3f980000.usb: irq 62, io mem 0x00000000
[ 0.720515] Init: Port Power? op_state=1
[ 0.720521] Init: Power Port (0)
[ 0.720734] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 0.720745] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.720754] usb usb1: Product: DWC OTG Controller
[ 0.720762] usb usb1: Manufacturer: Linux 4.14.34-v7+ dwc_otg_hcd
[ 0.720770] usb usb1: SerialNumber: 3f980000.usb
[ 0.721409] hub 1-0:1.0: USB hub found
[ 0.721451] hub 1-0:1.0: 1 port detected
[ 0.722029] dwc_otg: FIQ enabled
[ 0.722034] dwc_otg: NAK holdoff enabled
[ 0.722039] dwc_otg: FIQ split-transaction FSM enabled
[ 0.722048] Module dwc_common_port init
[ 0.722296] usbcore: registered new interface driver usb-storage
[ 0.722474] mousedev: PS/2 mouse device common for all mice
[ 0.722550] IR NEC protocol handler initialized
[ 0.722555] IR RC5(x/sz) protocol handler initialized
[ 0.722561] IR RC6 protocol handler initialized
[ 0.722567] IR JVC protocol handler initialized
[ 0.722572] IR Sony protocol handler initialized
[ 0.722577] IR SANYO protocol handler initialized
[ 0.722582] IR Sharp protocol handler initialized
[ 0.722587] IR MCE Keyboard/mouse protocol handler initialized
[ 0.722594] IR XMP protocol handler initialized
[ 0.723283] bcm2835-wdt 3f100000.watchdog: Broadcom BCM2835 watchdog timer
[ 0.723544] bcm2835-cpufreq: min=600000 max=1200000
[ 0.723896] sdhci: Secure Digital Host Controller Interface driver
[ 0.723901] sdhci: Copyright(c) Pierre Ossman
[ 0.724261] mmc-bcm2835 3f300000.mmc: could not get clk, deferring probe
[ 0.724587] sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe
[ 0.724679] sdhci-pltfm: SDHCI platform and OF driver helper
[ 0.726102] ledtrig-cpu: registered to indicate activity on CPUs
[ 0.726283] hidraw: raw HID events driver (C) Jiri Kosina
[ 0.726407] usbcore: registered new interface driver usbhid
[ 0.726413] usbhid: USB HID core driver
[ 0.727188] vchiq: vchiq_init_state: slot_zero = b7980000, is_master = 0
[ 0.728641] [vc_sm_connected_init]: start
[ 0.739161] [vc_sm_connected_init]: end - returning 0
[ 0.739745] Initializing XFRM netlink socket
[ 0.739769] NET: Registered protocol family 17
[ 0.739872] Key type dns_resolver registered
[ 0.740413] Registering SWP/SWPB emulation handler
[ 0.741001] registered taskstats version 1
[ 0.746970] uart-pl011 3f201000.serial: cts_event_workaround enabled
[ 0.747047] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 87, base_baud = 0) is a PL011 rev2
[ 0.748862] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
[ 0.748871] mmc-bcm2835 3f300000.mmc: DMA channel allocated
[ 0.802118] sdhost: log_buf @ b7907000 (f7907000)
[ 0.837905] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[ 0.839475] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 0.841043] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 0.843833] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[ 0.881499] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[ 0.882567] of_cfs_init
[ 0.882656] of_cfs_init: OK
[ 0.883246] Waiting for root device PARTUUID=0c830106-02...
[ 0.941724] Indeed it is in host mode hprt0 = 00021501
[ 1.020851] mmc1: new high speed SDIO card at address 0001
[ 1.042876] mmc0: host does not support reading read-only switch, assuming write-enable
[ 1.046001] mmc0: new high speed SDHC card at address aaaa
[ 1.046477] mmcblk0: mmc0:aaaa SL16G 14.8 GiB
[ 1.048863] mmcblk0: p1 p2
[ 1.066714] EXT4-fs (mmcblk0p2): INFO: recovery required on readonly filesystem
[ 1.066722] EXT4-fs (mmcblk0p2): write access will be enabled during recovery
[ 1.075729] EXT4-fs (mmcblk0p2): recovery complete
[ 1.079938] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[ 1.079992] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[ 1.087726] devtmpfs: mounted
[ 1.090899] Freeing unused kernel memory: 1024K
[ 1.151540] usb 1-1: new high-speed USB device number 2 using dwc_otg
[ 1.151666] Indeed it is in host mode hprt0 = 00001101
[ 1.391795] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
[ 1.391811] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 1.392527] hub 1-1:1.0: USB hub found
[ 1.392610] hub 1-1:1.0: 5 ports detected
[ 1.464634] systemd[1]: System time before build time, advancing clock.
[ 1.590833] NET: Registered protocol family 10
[ 1.592125] Segment Routing with IPv6
[ 1.605413] ip_tables: (C) 2000-2006 Netfilter Core Team
[ 1.628016] systemd[1]: systemd 232 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN)
[ 1.628567] systemd[1]: Detected architecture arm.
[ 1.633541] systemd[1]: Set hostname to raspberrypi.
[ 1.711668] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[ 1.851834] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
[ 1.851882] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 1.854626] smsc95xx v1.0.6
[ 1.955096] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:ef:b7:f8
[ 2.073925] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[ 2.074345] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
[ 2.074463] systemd[1]: Reached target Swap.
[ 2.074757] systemd[1]: Listening on udev Kernel Socket.
[ 2.075007] systemd[1]: Listening on Journal Socket (/dev/log).
[ 2.095283] systemd[1]: Created slice System Slice.
[ 2.098408] systemd[1]: Mounting Debug File System...
[ 2.189973] i2c /dev entries driver
[ 2.516225] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[ 2.582557] systemd-journald[92]: Received request to flush runtime journal from PID 1
[ 3.150771] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[ 3.154509] bcm2835_alsa bcm2835_alsa: card created with 8 channels
[ 3.371876] brcmfmac: F1 signature read @0x18000000=0x1541a9a6
[ 3.387679] brcmfmac: brcmf_fw_map_chip_to_name: using brcm/brcmfmac43430-sdio.bin for chip 0x00a9a6(43430) rev 0x000001
[ 3.387960] usbcore: registered new interface driver brcmfmac
[ 3.628839] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Oct 23 2017 03:55:53 version 7.45.98.38 (r674442 CY) FWID 01-e58d219f
[ 3.629655] brcmfmac: brcmf_c_preinit_dcmds: CLM version = API: 12.2 Data: 7.11.15 Compiler: 1.24.2 ClmImport: 1.24.1 Creation: 2014-05-26 10:53:55 Inc Data: 9.10.39 Inc Compiler: 1.29.4 Inc ClmImport: 1.36.3 Creation: 2017-10-23 03:47:14
[ 4.529300] uart-pl011 3f201000.serial: no DMA platform data
[ 5.390512] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 5.390583] brcmfmac: power management disabled
[ 5.465582] random: crng init done
[ 5.853760] Adding 102396k swap on /var/swap. Priority:-2 extents:1 across:102396k SSFS
[ 5.892712] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[ 5.892864] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[ 6.420595] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 9.093542] Bluetooth: Core ver 2.22
[ 9.093638] NET: Registered protocol family 31
[ 9.093646] Bluetooth: HCI device and connection manager initialized
[ 9.093671] Bluetooth: HCI socket layer initialized
[ 9.093684] Bluetooth: L2CAP socket layer initialized
[ 9.093720] Bluetooth: SCO socket layer initialized
[ 9.117196] Bluetooth: HCI UART driver ver 2.3
[ 9.117215] Bluetooth: HCI UART protocol H4 registered
[ 9.117221] Bluetooth: HCI UART protocol Three-wire (H5) registered
[ 9.117443] Bluetooth: HCI UART protocol Broadcom registered
[ 9.380735] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[ 9.380745] Bluetooth: BNEP filters: protocol multicast
[ 9.380760] Bluetooth: BNEP socket layer initialized
[ 9.444656] Bluetooth: RFCOMM TTY layer initialized
[ 9.444687] Bluetooth: RFCOMM socket layer initialized
[ 9.444708] Bluetooth: RFCOMM ver 1.11
[ 10.518586] fuse init (API version 7.26)
- printk의 시간표시 제어
$ cat /sys/module/printk/parameters/time Y $ sudo -s // root login $ echo 0 >/sys/module/printk/parameters/time $ cat /sys/module/printk/parameters/time // time parameter off N
- Usermode에서 kernel message 전송 (/dev/kmsg)
$ echo "Hello Kernel-World" > /dev/kmsg // Kernel Message 전송
$ dmesg // 확인결과 그대로 표시 , 흐음 추후 다시 테스트
.....
[ 209.198640] Hello Kernel-World
$ exit // root exit
- 실시간 Kernel Log 테스트
$ sudo cat /proc/kmsg & // Kernel Debug 시작 $ sudo -s $ echo "Hello Kernel-World" > /dev/kmsg // Kernel Debug Message 전송 12 [ 4148.928694] Hello Kernel-World $ dmesg // 확인 ..... [ 3980.591551] Hello Kernel-World
dmesg의 메시지가 많다보니, 보고 싶은 Message는 grep를 이용
http://elinux.org/Debugging_by_printing
http://man7.org/linux/man-pages/man1/dmesg.1.html
http://m.blog.naver.com/koromoon/220581683064
http://jybaek.tistory.com/130
1.2 syslog 의 Kernel Tag Message
아래의 message를 보기전에 항상 /etc/syslog.conf의 설정을 확인을 하자.
- Log 정보분석 (syslog의 kernel tag)
$ cat /var/log/messages // dmesg 보다 좀 더 자세한 정보 (memory 및 symbol)
Feb 17 15:59:58 raspberrypi kernel: [ 4.786727] vc4-drm soc:gpu: bound 3f806000.vec (ops vc4_vec_ops [vc4])
Feb 17 15:59:58 raspberrypi kernel: [ 4.786832] vc4-drm soc:gpu: bound 3f400000.hvs (ops vc4_hvs_ops [vc4])
Feb 17 15:59:58 raspberrypi kernel: [ 4.787107] vc4-drm soc:gpu: bound 3f206000.pixelvalve (ops vc4_crtc_ops [vc4])
Feb 17 15:59:58 raspberrypi kernel: [ 4.787330] vc4-drm soc:gpu: bound 3f207000.pixelvalve (ops vc4_crtc_ops [vc4])
Feb 17 15:59:58 raspberrypi kernel: [ 4.787542] vc4-drm soc:gpu: bound 3f807000.pixelvalve (ops vc4_crtc_ops [vc4])
Feb 17 15:59:58 raspberrypi kernel: [ 4.811151] vc4-drm soc:gpu: bound 3fc00000.v3d (ops vc4_v3d_ops [vc4])
Feb 17 15:59:58 raspberrypi kernel: [ 4.818536] [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 0
Feb 17 15:59:58 raspberrypi kernel: [ 4.818554] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
Feb 17 15:59:58 raspberrypi kernel: [ 4.818560] [drm] Driver supports precise vblank timestamp query.
Feb 17 15:59:58 raspberrypi kernel: [ 4.891580] ------------[ cut here ]------------
Feb 17 15:59:58 raspberrypi kernel: [ 4.891785] WARNING: CPU: 1 PID: 206 at drivers/gpu/drm/drm_atomic_helper.c:1240 drm_atomic_helper_wait_for_vblanks.part.0+0x268/0x26c [drm_kms_helper]
Feb 17 15:59:58 raspberrypi kernel: [ 4.891796] [CRTC:67:crtc-2] vblank wait timed out
Feb 17 15:59:58 raspberrypi kernel: [ 4.891802] Modules linked in: vc4(+) brcmfmac drm_kms_helper brcmutil drm snd_soc_core cfg80211 snd_compress snd_pcm_dmaengine snd_bcm2835(C) rfkill syscopyarea sysfillrect sysimgblt fb_sys_fops snd_pcm snd_timer snd i2c_bcm2835 uio_pdrv_genirq uio fixed i2c_dev ip_tables x_tables ipv6 cn
Feb 17 15:59:58 raspberrypi kernel: [ 4.891944] CPU: 1 PID: 206 Comm: systemd-udevd Tainted: G C 4.14.34-v7+ #1110
Feb 17 15:59:58 raspberrypi kernel: [ 4.891953] Hardware name: BCM2835
Feb 17 15:59:58 raspberrypi kernel: [ 4.891997] [8010ffd8] (unwind_backtrace) from [<8010c240>] (show_stack+0x20/0x24)
Feb 17 15:59:58 raspberrypi kernel: [ 4.892025] [8010c240] (show_stack) from [<807840a4>] (dump_stack+0xd4/0x118)
Feb 17 15:59:58 raspberrypi kernel: [ 4.892056] [807840a4] (dump_stack) from [<8011da54>] (__warn+0xf8/0x110)
.......
$ cat /var/log/syslog // Kernel (상위정보 포함) 과 init 관련 정보
....
Feb 17 15:59:58 raspberrypi kernel: [ 4.787107] vc4-drm soc:gpu: bound 3f206000.pixelvalve (ops vc4_crtc_ops [vc4])
Feb 17 15:59:58 raspberrypi kernel: [ 4.787330] vc4-drm soc:gpu: bound 3f207000.pixelvalve (ops vc4_crtc_ops [vc4])
Feb 17 15:59:58 raspberrypi kernel: [ 4.787542] vc4-drm soc:gpu: bound 3f807000.pixelvalve (ops vc4_crtc_ops [vc4])
Feb 17 15:59:58 raspberrypi kernel: [ 4.811151] vc4-drm soc:gpu: bound 3fc00000.v3d (ops vc4_v3d_ops [vc4])
Feb 17 15:59:58 raspberrypi kernel: [ 4.818536] [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 0
Feb 17 15:59:58 raspberrypi kernel: [ 4.818554] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
Feb 17 15:59:58 raspberrypi kernel: [ 4.818560] [drm] Driver supports precise vblank timestamp query.
Feb 17 15:59:58 raspberrypi kernel: [ 4.891580] ------------[ cut here ]------------
..........
Feb 17 15:59:59 raspberrypi dhcpcd-run-hooks[448]: wlan0: starting wpa_supplicant
Feb 17 15:59:59 raspberrypi systemd[1]: Received SIGRTMIN+21 from PID 210 (plymouthd).
Feb 17 15:59:59 raspberrypi systemd[1]: Started Hold until boot process finishes up.
Feb 17 15:59:59 raspberrypi systemd[1]: Started Terminate Plymouth Boot Screen.
2. Kernel의 proc를 이용한 Debug
2.1 proc를 이용하여 symbol table 정보 찾기
- Kernel 의 __log_buf 직접접근
상위 dmesg의 Virtual Kernel Memory Layout을 참조.
$ sudo grep __log_buf /proc/kallsyms // Kernel Symbol 에서 __log_buf 검색 80c9aad0 b __log_buf // Physical 과 Virtual Address Mapping (00000000->80000000) memory map $ sudo cat /proc/iomem // SOC의 Periperal Memory (Memory Mapped IO) 00000000-3b3fffff : System RAM // System RAM Address (Physcial Address) 00008000-00afffff : Kernel code // Kernel Code 00c00000-00d478b3 : Kernel data // Kernel Data (상위 symbol table 확인) 3f006000-3f006fff : dwc_otg 3f007000-3f007eff : /soc/dma@7e007000 3f00b840-3f00b84e : /soc/vchiq 3f00b880-3f00b8bf : /soc/mailbox@7e00b880 3f100000-3f100027 : /soc/watchdog@7e100000 3f101000-3f102fff : /soc/cprman@7e101000 3f200000-3f2000b3 : /soc/gpio@7e200000 3f201000-3f201fff : /soc/serial@7e201000 3f201000-3f201fff : /soc/serial@7e201000 3f202000-3f2020ff : /soc/mmc@7e202000 3f206000-3f2060ff : /soc/pixelvalve@7e206000 3f207000-3f2070ff : /soc/pixelvalve@7e207000 3f212000-3f212007 : /soc/thermal@7e212000 3f215000-3f215007 : /soc/aux@0x7e215000 3f300000-3f3000ff : /soc/mmc@7e300000 3f400000-3f405fff : /soc/hvs@7e400000 3f805000-3f805fff : /soc/i2c@7e805000 3f806000-3f806fff : /soc/vec@7e806000 3f807000-3f8070ff : /soc/pixelvalve@7e807000 3f808000-3f8080ff : /soc/hdmi@7e902000 3f902000-3f9025ff : /soc/hdmi@7e902000 3f980000-3f98ffff : dwc_otg 3fc00000-3fc00fff : /soc/v3d@7ec00000
- System RAM의 Symbol Table 정보확인
////////////////////////////////////////////////////////////////////////////////// // 상위에서 알아본 __log_buf 의 symbol table의 주소를 상위 Kernel data 에 적용 // 0x00c9aad0 = 0x00000000 (System RAM) + c9aad0 ( __log_buf) // 상위와 같이 Physical Address 기반으로 변경 ////////////////////////////////////////////////////////////////////////////////// $ sudo hexdump -s 0x00c9aad0 -n 80 -C /dev/mem // -n 80 print line or $ sudo hd -s 0x00c9aad0 -n 80000 /dev/mem // /dev/mem 접근가능하여 __log_buf 부분 확인 00c9aad0 00 00 00 00 00 00 00 00 34 00 21 00 00 00 00 c6 |........4.!.....| 00c9aae0 42 6f 6f 74 69 6e 67 20 4c 69 6e 75 78 20 6f 6e |Booting Linux on| 00c9aaf0 20 70 68 79 73 69 63 61 6c 20 43 50 55 20 30 78 | physical CPU 0x| 00c9ab00 30 00 00 00 00 00 00 00 00 00 00 00 a8 00 98 00 |0...............| 00c9ab10 00 00 00 a6 4c 69 6e 75 78 20 76 65 72 73 69 6f |....Linux versio| 00c9ab20 6e 20 34 2e 31 34 2e 33 34 2d 76 37 2b 20 28 64 |n 4.14.34-v7+ (d| 00c9ab30 63 34 40 64 63 34 2d 58 50 53 31 33 2d 39 33 33 |c4@dc4-XPS13-933| 00c9ab40 33 29 20 28 67 63 63 20 76 65 72 73 69 6f 6e 20 |3) (gcc version | 00c9ab50 34 2e 39 2e 33 20 28 63 72 6f 73 73 74 6f 6f 6c |4.9.3 (crosstool| 00c9ab60 2d 4e 47 20 63 72 6f 73 73 74 6f 6f 6c 2d 6e 67 |-NG crosstool-ng| 00c9ab70 2d 31 2e 32 32 2e 30 2d 38 38 2d 67 38 34 36 30 |-1.22.0-88-g8460| 00c9ab80 36 31 31 29 29 20 23 31 31 31 30 20 53 4d 50 20 |611)) #1110 SMP | 00c9ab90 4d 6f 6e 20 41 70 72 20 31 36 20 31 35 3a 31 38 |Mon Apr 16 15:18| ....... 00c9f9d0 02 00 00 00 2c 00 1c 00 00 00 00 c6 66 75 73 65 |....,.......fuse| 00c9f9e0 20 69 6e 69 74 20 28 41 50 49 20 76 65 72 73 69 | init (API versi| 00c9f9f0 6f 6e 20 37 2e 32 36 29 91 ec 35 b5 30 00 00 00 |on 7.26)..5.0...| 00c9fa00 24 00 12 00 00 00 01 82 48 65 6c 6c 6f 20 4b 65 |$.......Hello Ke| 00c9fa10 72 6e 65 6c 2d 57 6f 72 6c 64 00 00 00 00 00 00 |rnel-World......| 00c9fa20 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................| // 추후 uboot에서 load address도 확인 후 uImage or zImage 도 확인 (미확인) $ cat /proc/kallsyms // System.map 과 비교 80008000 T stext 80008000 T _text 8000808c t __create_page_tables 80008138 t __turn_mmu_on_loc 80008144 t __fixup_smp 800081ac t __fixup_smp_on_up 800081d0 t __fixup_pv_table 80008224 t __vet_atags ..............
System.map (CONFIG_KALLSYMS 설정)
https://en.wikipedia.org/wiki/System.map
http://www.embedded.com/design/debug-and-optimization/4441375/Self-testing-in-embedded-systems--Hardware-failure
2.2 이외 proc의 다양한 Kernel 정보
/proc/sys/kernel에서 기본적인 kernel 관련정보를 볼 수 있다.
$ ls /proc/sys/kernel/ auto_msgmni perf_event_max_stack cad_pid perf_event_mlock_kb cap_last_cap perf_event_paranoid core_pattern pid_max core_pipe_limit poweroff_cmd core_uses_pid print-fatal-signals ctrl-alt-del printk //이전의 printk 설정 및 보기 dmesg_restrict printk_delay domainname printk_devkmsg firmware_config printk_ratelimit hostname printk_ratelimit_burst hotplug pty keys random kptr_restrict randomize_va_space max_lock_depth real-root-dev modprobe sched_child_runs_first modules_disabled sched_rr_timeslice_ms msgmax sched_rt_period_us msgmnb sched_rt_runtime_us msgmni sem ngroups_max shm_rmid_forced osrelease shmall ostype shmmax overflowgid shmmni overflowuid sysctl_writes_strict panic sysrq panic_on_oops tainted panic_on_rcu_stall threads-max panic_on_warn timer_migration perf_cpu_time_max_percent usermodehelper perf_event_max_contexts_per_stack version $ cat /proc/sys/kernel/sched_rr_timeslice_ms 100
3. Kernel 의 debugfs 설정 및 profile
Kernel Config에서 Kernel hacking Menu에서 다양한 기능을 제공
Kernel의 menuconfig 에서 다양한 설정들을 확인필요
- Trace 기능
- KGDB
- Memory Debug 기능
3.1 debug File system (/sys/kernel/debug)
Kernel config에 따라 변경되기 때문에 Kernel 설정확인
/sys/kernel/debug 의 Filesystem을 이용하여 Kernel의 내용을 Debug 하는 방법을 소개
$ mount | grep debugfs // /sys/kernel/debug mount 되어있는지 확인
$ mount -t debugfs none /sys/kernel/debug // 필요할 경우 사용 , 요즘 기본으로 되어있음
$ sudo -s // root login
$ ls /sys/kernel/debug/
bcm2708_fb bluetooth dma_buf frontswap irq mmc1 pwm sched_features vchiq
bcm2835_thermal brcmfmac extfrag gpio kprobes pinctrl regmap sleep_time vc-mem
bdi cleancache f2fs hid memblock pm_genpd regulator tracing vc-smem
block clk fault_around_bytes ieee80211 mmc0 pm_qos sched_debug usb
$ cat /sys/kernel/debug/bluetooth/rfcomm // bluetooth 관련정보확인
b8:27:eb:45:1d:52 00:00:00:00:00:00 4 13
b8:27:eb:45:1d:52 00:00:00:00:00:00 4 7
b8:27:eb:45:1d:52 00:00:00:00:00:00 4 12
$ cat /sys/kernel/debug/usb/devices // USB Host에서 Device Descriptor 정보 lsusb로 확인가능
T: Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#= 1 Spd=480 MxCh= 1
B: Alloc= 0/800 us ( 0%), #Int= 0, #Iso= 0
D: Ver= 2.00 Cls=09(hub ) Sub=00 Prot=01 MxPS=64 #Cfgs= 1
P: Vendor=1d6b ProdID=0002 Rev= 4.19
S: Manufacturer=Linux 4.19.35-1.1.0+g0f9917c ehci_hcd
S: Product=EHCI Host Controller
S: SerialNumber=ci_hdrc.1
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr= 0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub ) Sub=00 Prot=00 Driver=hub
E: Ad=81(I) Atr=03(Int.) MxPS= 4 Ivl=256ms
............
$ cat /sys/kernel/debug/gpio // 상위 본인이 확인하고자 하는 정보 확인
$ cat /sys/kernel/debug/pinctrl // Pinmux 정보
$ /sys/kernel/debug/tracing //tracing 기능
https://www.kernel.org/doc/Documentation/filesystems/debugfs.txt
https://events.linuxfoundation.org/sites/events/files/slides/kernel_profiling_debugging_tools_0.pdf
3.2 Kernel Profile (oprofile)
- Kernel Config 설정변경
- CONFIG_PROFILING=y (General setup)
- CONFIG_OPROFILE=y
https://cateee.net/lkddb/web-lkddb/OPROFILE.html
- File system의 변경 및 설치 Package
- oprofile package 설치
- /var/lib/oprofile directory 필요
Oprofile Download
https://oprofile.sourceforge.io/download/
https://oprofile.sourceforge.io/examples/
http://oprofile.sourceforge.net/about/
Oprofile 관련내용
http://homepages.cwi.nl/~aeb/linux/profile.html
https://oprofile.sourceforge.io/doc/index.html
http://egloos.zum.com/furmuwon/v/10709926
Yocto Profile 관련 Manual
https://yoctoproject.org/docs/1.8/profile-manual/profile-manual.html
https://developer.ridgerun.com/wiki/index.php?title=Preparing_Yocto_Development_Environment_for_Debugging
https://wiki.yoctoproject.org/wiki/Tracing_and_Profiling